--Task-- name: benchmark-140 enabled: True class_name: GatlingTask source_name: overseer-0 source_namespace: >default< target_name: am target_namespace: >default< start: 0.0 stop: None timeout: not yet initialized for this Task as timeout was not explicitly defined, see updates below loop: False interval: None dependencies: [] wait_for: ['benchmark-130'] preceding_task: benchmark-130 options: {'duration': 3600, 'java-opts': '-Drealm=alpha -Duser_password=Pa_ssw0rd -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140-', 'testCase': 'idc.benchmark.Mix2024', 'testMode': 'open', 'throughput': 140} group_name: None Current dir: /mnt/disk1/xslou/workshop/lodestar-fork/pyrock ________________________________________________________________________________ [2024-11-21 01:16:05] benchmark-140 pre : N/A ________________________________________________________________________________ 2024-11-21 01:16:05 - INFO: Timeout for this Task has changed to 1h 12m (4320 seconds) 2024-11-21 01:16:05 - INFO: timeout was calculated based on simulation duration parameter Pod log file : /results/orders/benchmark-140/stdout.txt Pod log : /results/orders/benchmark-140 2024-11-21 01:16:05,857 INFO 2024-11-21 01:16:05,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-11-21 01:16:05,857 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:16:06,129 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:16:06,129 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:06,129 DEBUG --- stdout --- 2024-11-21 01:16:06,132 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:16:06,132 DEBUG --- stderr --- 2024-11-21 01:16:06,132 DEBUG ________________________________________________________________________________ [2024-11-21 01:16:06] benchmark-140 print_command : Display the command to be forwarded to overseer as an order ________________________________________________________________________________ 2024-11-21 01:16:06,132 INFO 2024-11-21 01:16:06,132 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:16:06,132 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:16:06,409 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:16:06,409 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:06,410 DEBUG --- stdout --- 2024-11-21 01:16:06,410 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:16:06,410 DEBUG --- stderr --- 2024-11-21 01:16:06,410 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-140" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=140 -Duser_password=Pa_ssw0rd" ________________________________________________________________________________ [2024-11-21 01:16:06] benchmark-140 create_order : Create order for overseer with the command to run ________________________________________________________________________________ 2024-11-21 01:16:06,410 INFO 2024-11-21 01:16:06,410 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:16:06,410 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:16:06,684 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:16:06,685 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:06,685 DEBUG --- stdout --- 2024-11-21 01:16:06,685 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:16:06,685 DEBUG --- stderr --- 2024-11-21 01:16:06,685 DEBUG Order file: /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/order.json { "name": "benchmark-140", "command": " /lodestar/lodestar.py run-gatling --simulation-class=\"com.forgerock.pyrock.Loadtest\" --run-description=\"idc.benchmark.Mix2024@perf-benchmark\" --results-folder=\"/results/gatling/benchmark-140\" --no-reports --simulation-jvm-args=\"-XX:+ExitOnOutOfMemoryError -Xmx4G\" --simulation-system-properties=\"-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=140 -Duser_password=Pa_ssw0rd\"", "out-dir": "/results/orders/benchmark-140" } ________________________________________________________________________________ [2024-11-21 01:16:06] benchmark-140 loop_until_ready : Wait for preceding task to finish if it uses same Overseer as a source, then loop for max_time until Overseer pod status is READY to accept order :param max_time: periodically check overseer status for this many seconds at maximum :param interval: interval between two periodical checks :return: ________________________________________________________________________________ 2024-11-21 01:16:06,688 INFO 2024-11-21 01:16:06,688 INFO [loop_until]: curl --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt | grep "WAITING" 2024-11-21 01:16:06,688 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 01:16:07,055 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 01:16:07,055 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:07,055 DEBUG --- stdout --- 2024-11-21 01:16:07,055 DEBUG WAITING 2024-11-21 01:16:07,055 DEBUG --- stderr --- 2024-11-21 01:16:07,055 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 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 7 100 7 0 0 23 0 --:--:-- --:--:-- --:--:-- 23 ________________________________________________________________________________ [2024-11-21 01:16:07] benchmark-140 start_order : Send the order to the overseer pod ________________________________________________________________________________ 2024-11-21 01:16:07,056 INFO 2024-11-21 01:16:07,056 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:16:07,056 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:16:07,328 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:16:07,328 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:07,329 DEBUG --- stdout --- 2024-11-21 01:16:07,329 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:16:07,329 DEBUG --- stderr --- 2024-11-21 01:16:07,329 DEBUG 2024-11-21 01:16:07,329 INFO 2024-11-21 01:16:07,329 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/order.json overseer-0-6644bb6697-rchxr:/results/orders/order.json 2024-11-21 01:16:07,329 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 01:16:08,660 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:08,660 DEBUG --- stdout --- 2024-11-21 01:16:08,660 DEBUG 2024-11-21 01:16:08,660 DEBUG --- stderr --- 2024-11-21 01:16:08,660 DEBUG Order has been successfully forwarded to overseer 2024-11-21 01:16:08 - INFO: Check if Gatling simulation started successfully 2024-11-21 01:16:08,661 INFO 2024-11-21 01:16:08,661 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 01:16:08,661 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 01:16:08,935 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 01:16:08,935 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:08,935 DEBUG --- stdout --- 2024-11-21 01:16:08,935 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 01:16:08,935 DEBUG --- stderr --- 2024-11-21 01:16:08,935 DEBUG 2024-11-21 01:16:08,935 INFO 2024-11-21 01:16:08,935 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- head --lines 5000 /results/orders/benchmark-140/stdout.txt | grep "Simulation com.forgerock.pyrock.Loadtest started..." 2024-11-21 01:16:08,935 INFO [loop_until]: (max_time=300, interval=5, expected_rc=[0] 2024-11-21 01:16:09,639 INFO [loop_until]: Function succeeded after 0s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 01:16:15,361 INFO [loop_until]: Function succeeded after 6s (rc=0) - failed to find expected output: Simulation com.forgerock.pyrock.Loadtest started... - retry 2024-11-21 01:16:21,072 INFO [loop_until]: Function succeeded after 12s (rc=0) - expected pattern found 2024-11-21 01:16:21,072 INFO [loop_until]: OK (rc = 0) 2024-11-21 01:16:21,072 DEBUG --- stdout --- 2024-11-21 01:16:21,072 DEBUG 2024-11-21 01:16:09,620 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpkc9iiwpp 2024-11-21 01:16:09,622 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-140" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=140 -Duser_password=**** [INFO] Scanning for projects... [INFO] [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- [INFO] Building pyrock-gatling-simulation 3.12.0 [INFO] from pom.xml [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> [INFO] [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- [INFO] skip non existing resourceDirectory /tmp/tmpkc9iiwpp/src/main/resources [INFO] [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- [INFO] No sources to compile [INFO] [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- [INFO] Copying 2 resources from src/test/resources to target/test-classes [INFO] [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- [INFO] Nothing to compile - all classes are up to date. [INFO] [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- [INFO] compiling 38 Scala sources to /tmp/tmpkc9iiwpp/target/test-classes ... [INFO] compile in 6.9 s [INFO] [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< [INFO] [INFO] [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- [INFO] Running simulation com.forgerock.pyrock.Loadtest. Gatling 3.13.1 is available! (you're using 3.12.0) System property think_time_multiplier not set. No think time emulation will be done in the simulation. Simulation com.forgerock.pyrock.Loadtest started... 01:16:20.853 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 01:16:21,072 DEBUG --- stderr --- 2024-11-21 01:16:21,072 DEBUG ________________________________________________________________________________ [2024-11-21 01:16:21] benchmark-140 wait_stop_by_itself : Wait for the order to stop by itself ________________________________________________________________________________ Task may stop by itself (no stop defined in configuration file), wait until overseer ends the order - timeout is 1h 12m. Waiting for status (curl --fail --insecure https://overseer-0.xlou.iam.xlou-cdm.engineeringpit.com/orders/status.txt) == WAITING Order is running since 2m, retry Order is running since 4m, retry Order is running since 6m, retry Order is running since 8m 01s, retry Order is running since 10m 01s, retry Order is running since 12m 01s, retry Order is running since 14m 02s, retry Order is running since 16m 02s, retry Order is running since 18m 02s, retry Order is running since 20m 02s, retry Order is running since 22m 03s, retry Order is running since 24m 03s, retry Order is running since 26m 03s, retry Order is running since 28m 04s, retry Order is running since 30m 04s, retry Order is running since 32m 04s, retry Order is running since 34m 04s, retry Order is running since 36m 05s, retry Order is running since 38m 05s, retry Order is running since 40m 05s, retry Order is running since 42m 06s, retry Order is running since 44m 06s, retry Order is running since 46m 06s, retry Order is running since 48m 06s, retry Order is running since 50m 07s, retry Order is running since 52m 07s, retry Order is running since 54m 07s, retry Order is running since 56m 08s, retry Order is running since 58m 08s, retry PASS : Order stopped by itself after 1h and before timeout (1h 12m) ________________________________________________________________________________ [2024-11-21 02:16:29] benchmark-140 stop_order : Stop the order on overseer pod ________________________________________________________________________________ 2024-11-21 02:16:29,768 INFO 2024-11-21 02:16:29,769 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:29,769 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:30,074 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:30,074 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:30,074 DEBUG --- stdout --- 2024-11-21 02:16:30,074 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:30,074 DEBUG --- stderr --- 2024-11-21 02:16:30,074 DEBUG 2024-11-21 02:16:30,074 INFO 2024-11-21 02:16:30,074 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr -- rm -f /results/orders/order.json 2024-11-21 02:16:30,075 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 02:16:30,840 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:30,840 DEBUG --- stdout --- 2024-11-21 02:16:30,840 DEBUG 2024-11-21 02:16:30,840 DEBUG --- stderr --- 2024-11-21 02:16:30,840 DEBUG Order ran during 1h ________________________________________________________________________________ [2024-11-21 02:16:30] benchmark-140 download_logs : Download individual order files ________________________________________________________________________________ 2024-11-21 02:16:30 - PASS: file already downloaded /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/order.json 2024-11-21 02:16:30,841 INFO 2024-11-21 02:16:30,841 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:30,841 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:31,113 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:31,113 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:31,113 DEBUG --- stdout --- 2024-11-21 02:16:31,113 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:31,113 DEBUG --- stderr --- 2024-11-21 02:16:31,113 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 02:16:31,114 INFO 2024-11-21 02:16:31,114 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:31,114 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:31,386 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:31,386 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:31,386 DEBUG --- stdout --- 2024-11-21 02:16:31,386 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:31,386 DEBUG --- stderr --- 2024-11-21 02:16:31,386 DEBUG 2024-11-21 02:16:31,387 INFO 2024-11-21 02:16:31,387 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-140/rc.txt" ]; then echo "/results/orders/benchmark-140/rc.txt file found"; exit 0; else echo "/results/orders/benchmark-140/rc.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-140/rc.txt file found" 2024-11-21 02:16:31,387 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 02:16:32,178 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 02:16:32,178 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:32,178 DEBUG --- stdout --- 2024-11-21 02:16:32,178 DEBUG /results/orders/benchmark-140/rc.txt file found 2024-11-21 02:16:32,178 DEBUG --- stderr --- 2024-11-21 02:16:32,178 DEBUG 2024-11-21 02:16:32,178 INFO 2024-11-21 02:16:32,178 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:32,178 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:32,451 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:32,452 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:32,452 DEBUG --- stdout --- 2024-11-21 02:16:32,452 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:32,452 DEBUG --- stderr --- 2024-11-21 02:16:32,452 DEBUG 2024-11-21 02:16:32,452 INFO 2024-11-21 02:16:32,452 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-140/rc.txt 2024-11-21 02:16:33,235 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 02:16:33,235 DEBUG --- stdout --- 2024-11-21 02:16:33,236 DEBUG 4 /results/orders/benchmark-140/rc.txt 2024-11-21 02:16:33,236 DEBUG --- stderr --- 2024-11-21 02:16:33,236 DEBUG 2024-11-21 02:16:33,236 INFO - Download file (size 4k) 2024-11-21 02:16:33,236 INFO 2024-11-21 02:16:33,236 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:33,236 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:33,509 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:33,510 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:33,510 DEBUG --- stdout --- 2024-11-21 02:16:33,510 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:33,510 DEBUG --- stderr --- 2024-11-21 02:16:33,510 DEBUG source : /results/orders/benchmark-140/rc.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/rc.txt 2024-11-21 02:16:33,510 INFO 2024-11-21 02:16:33,510 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:33,510 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:33,784 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:33,784 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:33,784 DEBUG --- stdout --- 2024-11-21 02:16:33,784 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:33,784 DEBUG --- stderr --- 2024-11-21 02:16:33,784 DEBUG 2024-11-21 02:16:33,784 INFO 2024-11-21 02:16:33,785 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-140/rc.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/rc.txt 2024-11-21 02:16:33,785 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 02:16:34,525 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:34,525 DEBUG --- stdout --- 2024-11-21 02:16:34,525 DEBUG tar: Removing leading `/' from member names 2024-11-21 02:16:34,525 DEBUG --- stderr --- 2024-11-21 02:16:34,525 DEBUG 2024-11-21 02:16:34,525 INFO 2024-11-21 02:16:34,525 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:34,525 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:34,798 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:34,798 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:34,798 DEBUG --- stdout --- 2024-11-21 02:16:34,798 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:34,798 DEBUG --- stderr --- 2024-11-21 02:16:34,798 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 02:16:34,798 INFO 2024-11-21 02:16:34,798 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:34,798 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:35,070 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:35,070 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:35,070 DEBUG --- stdout --- 2024-11-21 02:16:35,070 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:35,070 DEBUG --- stderr --- 2024-11-21 02:16:35,070 DEBUG 2024-11-21 02:16:35,071 INFO 2024-11-21 02:16:35,071 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-140/stderr.txt" ]; then echo "/results/orders/benchmark-140/stderr.txt file found"; exit 0; else echo "/results/orders/benchmark-140/stderr.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-140/stderr.txt file found" 2024-11-21 02:16:35,071 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 02:16:35,852 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 02:16:35,852 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:35,852 DEBUG --- stdout --- 2024-11-21 02:16:35,852 DEBUG /results/orders/benchmark-140/stderr.txt file found 2024-11-21 02:16:35,852 DEBUG --- stderr --- 2024-11-21 02:16:35,852 DEBUG 2024-11-21 02:16:35,852 INFO 2024-11-21 02:16:35,852 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:35,852 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:36,130 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:36,130 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:36,130 DEBUG --- stdout --- 2024-11-21 02:16:36,130 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:36,130 DEBUG --- stderr --- 2024-11-21 02:16:36,130 DEBUG 2024-11-21 02:16:36,130 INFO 2024-11-21 02:16:36,131 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-140/stderr.txt 2024-11-21 02:16:36,939 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 02:16:36,939 DEBUG --- stdout --- 2024-11-21 02:16:36,939 DEBUG 0 /results/orders/benchmark-140/stderr.txt 2024-11-21 02:16:36,939 DEBUG --- stderr --- 2024-11-21 02:16:36,939 DEBUG 2024-11-21 02:16:36,939 INFO - Download file (size 0k) 2024-11-21 02:16:36,939 INFO 2024-11-21 02:16:36,939 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:36,939 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:37,211 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:37,211 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:37,211 DEBUG --- stdout --- 2024-11-21 02:16:37,211 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:37,211 DEBUG --- stderr --- 2024-11-21 02:16:37,211 DEBUG source : /results/orders/benchmark-140/stderr.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stderr.txt 2024-11-21 02:16:37,212 INFO 2024-11-21 02:16:37,212 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:37,212 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:37,484 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:37,484 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:37,484 DEBUG --- stdout --- 2024-11-21 02:16:37,484 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:37,484 DEBUG --- stderr --- 2024-11-21 02:16:37,484 DEBUG 2024-11-21 02:16:37,484 INFO 2024-11-21 02:16:37,484 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-140/stderr.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stderr.txt 2024-11-21 02:16:37,484 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 02:16:38,227 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:38,227 DEBUG --- stdout --- 2024-11-21 02:16:38,227 DEBUG tar: Removing leading `/' from member names 2024-11-21 02:16:38,227 DEBUG --- stderr --- 2024-11-21 02:16:38,227 DEBUG 2024-11-21 02:16:38,227 INFO 2024-11-21 02:16:38,227 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:38,227 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:38,499 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:38,499 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:38,499 DEBUG --- stdout --- 2024-11-21 02:16:38,499 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:38,500 DEBUG --- stderr --- 2024-11-21 02:16:38,500 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 02:16:38,500 INFO 2024-11-21 02:16:38,500 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:38,500 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:38,802 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:38,802 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:38,802 DEBUG --- stdout --- 2024-11-21 02:16:38,802 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:38,802 DEBUG --- stderr --- 2024-11-21 02:16:38,802 DEBUG 2024-11-21 02:16:38,803 INFO 2024-11-21 02:16:38,803 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-140/stdout.txt" ]; then echo "/results/orders/benchmark-140/stdout.txt file found"; exit 0; else echo "/results/orders/benchmark-140/stdout.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-140/stdout.txt file found" 2024-11-21 02:16:38,803 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 02:16:39,583 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 02:16:39,583 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:39,583 DEBUG --- stdout --- 2024-11-21 02:16:39,583 DEBUG /results/orders/benchmark-140/stdout.txt file found 2024-11-21 02:16:39,583 DEBUG --- stderr --- 2024-11-21 02:16:39,583 DEBUG 2024-11-21 02:16:39,583 INFO 2024-11-21 02:16:39,583 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:39,583 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:39,855 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:39,855 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:39,855 DEBUG --- stdout --- 2024-11-21 02:16:39,855 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:39,855 DEBUG --- stderr --- 2024-11-21 02:16:39,855 DEBUG 2024-11-21 02:16:39,855 INFO 2024-11-21 02:16:39,855 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-140/stdout.txt 2024-11-21 02:16:40,639 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 02:16:40,639 DEBUG --- stdout --- 2024-11-21 02:16:40,639 DEBUG 1879128 /results/orders/benchmark-140/stdout.txt 2024-11-21 02:16:40,639 DEBUG --- stderr --- 2024-11-21 02:16:40,639 DEBUG 2024-11-21 02:16:40,639 INFO - Download file (size 1879128k) 2024-11-21 02:16:40,640 INFO 2024-11-21 02:16:40,640 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:40,640 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:40,912 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:40,913 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:40,913 DEBUG --- stdout --- 2024-11-21 02:16:40,913 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:40,913 DEBUG --- stderr --- 2024-11-21 02:16:40,913 DEBUG source : /results/orders/benchmark-140/stdout.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stdout.txt 2024-11-21 02:16:40,913 INFO 2024-11-21 02:16:40,913 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:16:40,913 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:16:41,188 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:16:41,188 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:16:41,188 DEBUG --- stdout --- 2024-11-21 02:16:41,188 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:16:41,188 DEBUG --- stderr --- 2024-11-21 02:16:41,188 DEBUG 2024-11-21 02:16:41,189 INFO 2024-11-21 02:16:41,189 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-140/stdout.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stdout.txt 2024-11-21 02:16:41,189 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 02:17:33,855 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:33,855 DEBUG --- stdout --- 2024-11-21 02:17:33,855 DEBUG tar: Removing leading `/' from member names 2024-11-21 02:17:33,855 DEBUG --- stderr --- 2024-11-21 02:17:33,855 DEBUG ________________________________________________________________________________ [2024-11-21 02:17:33] benchmark-140 show_cmd : Display order command ________________________________________________________________________________ 2024-11-21 02:17:33,855 INFO 2024-11-21 02:17:33,855 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:17:33,855 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:17:34,127 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:17:34,127 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:34,127 DEBUG --- stdout --- 2024-11-21 02:17:34,127 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:17:34,127 DEBUG --- stderr --- 2024-11-21 02:17:34,127 DEBUG Checking pod: overseer-0-6644bb6697-rchxr for file exists, if not wait. 2024-11-21 02:17:34,127 INFO 2024-11-21 02:17:34,127 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:17:34,127 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:17:34,399 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:17:34,399 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:34,399 DEBUG --- stdout --- 2024-11-21 02:17:34,399 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:17:34,399 DEBUG --- stderr --- 2024-11-21 02:17:34,399 DEBUG 2024-11-21 02:17:34,400 INFO 2024-11-21 02:17:34,400 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- bash -c 'if [ -f "/results/orders/benchmark-140/cmd.txt" ]; then echo "/results/orders/benchmark-140/cmd.txt file found"; exit 0; else echo "/results/orders/benchmark-140/cmd.txt file not found"; exit 1; fi' | grep "/results/orders/benchmark-140/cmd.txt file found" 2024-11-21 02:17:34,400 INFO [loop_until]: (max_time=180, interval=5, expected_rc=[0] 2024-11-21 02:17:35,174 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected pattern found 2024-11-21 02:17:35,174 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:35,174 DEBUG --- stdout --- 2024-11-21 02:17:35,174 DEBUG /results/orders/benchmark-140/cmd.txt file found 2024-11-21 02:17:35,174 DEBUG --- stderr --- 2024-11-21 02:17:35,174 DEBUG 2024-11-21 02:17:35,175 INFO 2024-11-21 02:17:35,175 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:17:35,175 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:17:35,454 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:17:35,454 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:35,454 DEBUG --- stdout --- 2024-11-21 02:17:35,454 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:17:35,454 DEBUG --- stderr --- 2024-11-21 02:17:35,454 DEBUG 2024-11-21 02:17:35,454 INFO 2024-11-21 02:17:35,454 INFO [run_command]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm exec overseer-0-6644bb6697-rchxr --stdin -- du -k /results/orders/benchmark-140/cmd.txt 2024-11-21 02:17:36,232 INFO [run_command]: OK (rc = 0 - expected to be in [0]) 2024-11-21 02:17:36,232 DEBUG --- stdout --- 2024-11-21 02:17:36,232 DEBUG 4 /results/orders/benchmark-140/cmd.txt 2024-11-21 02:17:36,233 DEBUG --- stderr --- 2024-11-21 02:17:36,233 DEBUG 2024-11-21 02:17:36,233 INFO - Download file (size 4k) 2024-11-21 02:17:36,233 INFO 2024-11-21 02:17:36,233 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:17:36,233 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:17:36,508 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:17:36,508 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:36,508 DEBUG --- stdout --- 2024-11-21 02:17:36,508 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:17:36,508 DEBUG --- stderr --- 2024-11-21 02:17:36,508 DEBUG source : /results/orders/benchmark-140/cmd.txt @ overseer-0-6644bb6697-rchxr destination : /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/cmd.txt 2024-11-21 02:17:36,509 INFO 2024-11-21 02:17:36,509 INFO [loop_until]: awk -F" " "{print NF}" <<< `kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm get pods --selector app=overseer-0 --output jsonpath={.items[*].metadata.name}` | grep 1 2024-11-21 02:17:36,509 INFO [loop_until]: (max_time=180, interval=10, expected_rc=[0] 2024-11-21 02:17:36,782 INFO [loop_until]: Function succeeded after 0s (rc=0) - expected number of elements found 2024-11-21 02:17:36,782 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:36,782 DEBUG --- stdout --- 2024-11-21 02:17:36,782 DEBUG overseer-0-6644bb6697-rchxr 2024-11-21 02:17:36,782 DEBUG --- stderr --- 2024-11-21 02:17:36,782 DEBUG 2024-11-21 02:17:36,782 INFO 2024-11-21 02:17:36,782 INFO [loop_until]: kubectl --namespace=xlou --context=gke_engineeringpit_us-east1-d_xlou-cdm cp --retries=100 overseer-0-6644bb6697-rchxr:/results/orders/benchmark-140/cmd.txt /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/cmd.txt 2024-11-21 02:17:36,782 INFO [loop_until]: (max_time=-1, interval=5, expected_rc=[0] 2024-11-21 02:17:37,524 INFO [loop_until]: OK (rc = 0) 2024-11-21 02:17:37,524 DEBUG --- stdout --- 2024-11-21 02:17:37,524 DEBUG tar: Removing leading `/' from member names 2024-11-21 02:17:37,524 DEBUG --- stderr --- 2024-11-21 02:17:37,524 DEBUG 2024-11-21 02:17:37,524 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/cmd.txt is small (1 lines), printing all lines: 2024-11-21 02:17:37,524 DEBUG ----- output ----- 2024-11-21 02:17:37,524 DEBUG /lodestar/lodestar.py run-gatling --simulation-class="com.forgerock.pyrock.Loadtest" --run-description="idc.benchmark.Mix2024@perf-benchmark" --results-folder="/results/gatling/benchmark-140" --no-reports --simulation-jvm-args="-XX:+ExitOnOutOfMemoryError -Xmx4G" --simulation-system-properties="-Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=M@ythe4th -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=140 -Duser_password=Pa_ssw0rd" 2024-11-21 02:17:37,524 INFO ________________________________________________________________________________ [2024-11-21 02:17:37] benchmark-140 show_rc : Display rc order ________________________________________________________________________________ 2024-11-21 02:17:37,525 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/rc.txt is small (1 lines), printing all lines: 2024-11-21 02:17:37,525 DEBUG ----- output ----- 2024-11-21 02:17:37,525 DEBUG CMD SUCCESS: command returns code 0 (expected [0, -9, 143, 137, -15]) 2024-11-21 02:17:37,525 INFO ________________________________________________________________________________ [2024-11-21 02:17:37] benchmark-140 show_stdout : Display stdout order ________________________________________________________________________________ 2024-11-21 02:17:39,827 DEBUG [print_head_tail]: Print head (100 lines) and tail (100 lines) of input file (/mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stdout.txt is 16963370 lines): 2024-11-21 02:17:39,827 DEBUG ----- output ----- 2024-11-21 02:17:39,827 INFO 2024-11-21 01:16:09,620 INFO pom.xml and Gatling Scala files copied from /home/jenkins/lodestar/pyrock/shared/clients/gatling to temporary folder /tmp/tmpkc9iiwpp 2024-11-21 02:17:39,827 INFO 2024-11-21 01:16:09,622 INFO Running Gatling simulation with command: mvn gatling:test --batch-mode -Dgatling.simulationClass="com.forgerock.pyrock.Loadtest" -Dgatling.runDescription="..." -Dgatling.resultsFolder="/results/gatling/benchmark-140" -Dgatling.noReports=true -Dgatling.jvmArgs="-XX:+ExitOnOutOfMemoryError,-Xmx4G" -Dgatling.propagateSystemProperties=true -Dam_host=openam-perf-benchmark.forgeblocks.com -Dam_oauth2_scope=openid^fr:idm:* -DamadminPassword=**** -DamadminUsername=xiaosong.lou@pingidentity.com -Dduration=3600 -Didc=true -Dlogin_cookie=9b75a55744995d0 -Dnum_users=200000 -Doauth2_client_id=endUserUIClient -Doauth2_redirect_uri=/enduser/appAuthHelperRedirect.html -Dprefix=self140- -Drealm=alpha -DtestCase=idc.benchmark.Mix2024 -DtestMode=open -Dthroughput=140 -Duser_password=**** 2024-11-21 02:17:39,827 INFO [INFO] Scanning for projects... 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] -----------< com.forgerock.pyrock:pyrock-gatling-simulation >----------- 2024-11-21 02:17:39,827 INFO [INFO] Building pyrock-gatling-simulation 3.12.0 2024-11-21 02:17:39,827 INFO [INFO] from pom.xml 2024-11-21 02:17:39,827 INFO [INFO] --------------------------------[ jar ]--------------------------------- 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] >>> gatling:4.9.6:test (default-cli) > test-compile @ pyrock-gatling-simulation >>> 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] --- resources:3.3.1:resources (default-resources) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,827 INFO [INFO] skip non existing resourceDirectory /tmp/tmpkc9iiwpp/src/main/resources 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] --- compiler:3.13.0:compile (default-compile) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,827 INFO [INFO] No sources to compile 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] --- resources:3.3.1:testResources (default-testResources) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,827 INFO [INFO] Copying 2 resources from src/test/resources to target/test-classes 2024-11-21 02:17:39,827 INFO [INFO] 2024-11-21 02:17:39,827 INFO [INFO] --- compiler:3.13.0:testCompile (default-testCompile) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,827 INFO [INFO] Nothing to compile - all classes are up to date. 2024-11-21 02:17:39,828 INFO [INFO] 2024-11-21 02:17:39,828 INFO [INFO] --- scala:4.9.2:testCompile (default) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,828 INFO [INFO] compiling 38 Scala sources to /tmp/tmpkc9iiwpp/target/test-classes ... 2024-11-21 02:17:39,828 INFO [INFO] compile in 6.9 s 2024-11-21 02:17:39,828 INFO [INFO] 2024-11-21 02:17:39,828 INFO [INFO] <<< gatling:4.9.6:test (default-cli) < test-compile @ pyrock-gatling-simulation <<< 2024-11-21 02:17:39,828 INFO [INFO] 2024-11-21 02:17:39,828 INFO [INFO] 2024-11-21 02:17:39,828 INFO [INFO] --- gatling:4.9.6:test (default-cli) @ pyrock-gatling-simulation --- 2024-11-21 02:17:39,828 INFO [INFO] Running simulation com.forgerock.pyrock.Loadtest. 2024-11-21 02:17:39,828 INFO Gatling 3.13.1 is available! (you're using 3.12.0) 2024-11-21 02:17:39,828 INFO System property think_time_multiplier not set. No think time emulation will be done in the simulation. 2024-11-21 02:17:39,828 INFO Simulation com.forgerock.pyrock.Loadtest started... 2024-11-21 02:17:39,828 INFO 01:16:20.853 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,828 INFO 01:16:21.920 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,828 INFO 01:16:22.325 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,828 INFO 01:16:24.667 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,828 INFO 2024-11-21 02:17:39,828 INFO ================================================================================ 2024-11-21 02:17:39,828 INFO 2024-11-21 01:16:25 GMT 5s elapsed 2024-11-21 02:17:39,828 INFO ---- Requests ------------------------------------------------------------------ 2024-11-21 02:17:39,828 INFO > Global (OK=654 KO=0 ) 2024-11-21 02:17:39,828 INFO > restLoginInitiate (OK=54 KO=0 ) 2024-11-21 02:17:39,828 INFO > restLoginUsernamePasswordCallback (OK=52 KO=0 ) 2024-11-21 02:17:39,828 INFO > Skip 2FA (OK=21 KO=0 ) 2024-11-21 02:17:39,828 INFO > User Authorize PKCE stage (OK=55 KO=0 ) 2024-11-21 02:17:39,828 INFO > User AccessToken PKCE stage (OK=55 KO=0 ) 2024-11-21 02:17:39,828 INFO > getIdToken (OK=4 KO=0 ) 2024-11-21 02:17:39,828 INFO > getIdToken Redirect 1 (OK=4 KO=0 ) 2024-11-21 02:17:39,828 INFO > createOrganization (OK=4 KO=0 ) 2024-11-21 02:17:39,828 INFO > queryOrganization (OK=4 KO=0 ) 2024-11-21 02:17:39,828 INFO > deleteOrganization (OK=4 KO=0 ) 2024-11-21 02:17:39,828 INFO > GetUUid (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 1 (OK=18 KO=0 ) 2024-11-21 02:17:39,828 INFO > GetOpenidConfig (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 1 Redirect 1 (OK=18 KO=0 ) 2024-11-21 02:17:39,828 INFO > CreatePolicy (OK=10 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI AM idFromSession (OK=14 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI AM validateGoto (OK=14 KO=0 ) 2024-11-21 02:17:39,828 INFO > tokenUserinfo (OK=8 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 2 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 2 Redirect 1 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > restloginProgressiveProfileCallback (OK=6 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI Enduser appAuthHelper1 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI Enduser appAuthHelper2 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 3 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Post-Login - stage 3 Redirect 1 (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM uiconfig (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI Enduser sessioncheck (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM version (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM login (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM privilege (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM features (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM managed user schema (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM user (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM dashboard (OK=13 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI IDM oidcToken (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > userinfo (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Logout (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI-Logout Redirect 1 (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI AM endsession (OK=12 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI AM revoke1 (OK=10 KO=0 ) 2024-11-21 02:17:39,828 INFO > UI AM revoke2 (OK=10 KO=0 ) 2024-11-21 02:17:39,828 INFO > RootUserinfo (OK=4 KO=0 ) 2024-11-21 02:17:39,829 INFO > loginTreeWorkflow_restLoginInitiate (OK=3 KO=0 ) 2024-11-21 02:17:39,829 INFO > loginTreeWorkflow_restLoginUsernamePasswordCallback (OK=3 KO=0 ) 2024-11-21 02:17:39,829 INFO ---- Errors -------------------------------------------------------------------- 2024-11-21 02:17:39,829 INFO > tokenUserinfo: No attribute named 'access_token' is defined 4 (100.0%) 2024-11-21 02:17:39,829 INFO 2024-11-21 02:17:39,829 INFO ---- idc.benchmark.Mix2024 ----------------------------------------------------- 2024-11-21 02:17:39,829 INFO [- ] 0% 2024-11-21 02:17:39,829 INFO waiting: 505516 / active: 29 / done: 29 2024-11-21 02:17:39,829 INFO ================================================================================ 2024-11-21 02:17:39,829 INFO 2024-11-21 02:17:39,829 INFO 01:16:28.092 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,829 INFO 01:16:28.403 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,829 INFO 01:16:29.661 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,829 INFO 01:16:30.158 [ERROR] i.g.h.a.HttpRequestAction - Failed to build request tokenUserinfo: No attribute named 'access_token' is defined 2024-11-21 02:17:39,829 INFO [...] 2024-11-21 02:17:42,820 INFO 02:16:20.583 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 02:17:42,820 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 501401: j.i.IOException: Premature close 2024-11-21 02:17:42,820 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 02:17:42,820 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 02:17:42,820 INFO Request: 2024-11-21 02:17:42,820 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 02:17:42,820 INFO ========================= 2024-11-21 02:17:42,820 INFO Session: 2024-11-21 02:17:42,820 INFO Session(idc.benchmark.Mix2024,501396,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.62812, randomPolicyName -> testPolicy753384, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@7c250be6, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@46393765),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007cd850698000@23fc68bc,io.netty.channel.epoll.EpollEventLoop@239b0f9d) 2024-11-21 02:17:42,820 INFO ========================= 2024-11-21 02:17:42,820 INFO HTTP request: 2024-11-21 02:17:42,821 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 02:17:42,821 INFO headers: 2024-11-21 02:17:42,821 INFO accept: application/json 2024-11-21 02:17:42,821 INFO content-type: application/json 2024-11-21 02:17:42,821 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1 2024-11-21 02:17:42,821 INFO X-Forwarded-For: 42.42.42.42 2024-11-21 02:17:42,821 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 02:17:42,821 INFO content-length: 0 2024-11-21 02:17:42,821 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO HTTP response: 2024-11-21 02:17:42,821 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 02:17:42,821 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 501400: j.i.IOException: Premature close 2024-11-21 02:17:42,821 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - Request 'restLoginInitiate' failed for user 501397: j.i.IOException: Premature close 2024-11-21 02:17:42,821 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 02:17:42,821 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 02:17:42,821 INFO Request: 2024-11-21 02:17:42,821 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO Session: 2024-11-21 02:17:42,821 INFO Session(idc.benchmark.Mix2024,501400,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.126550, randomPolicyName -> testPolicy982421, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@29a7b341, fake-user-agent -> Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/17.17134, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@58d18ab4),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007cd850698000@23fc68bc,io.netty.channel.epoll.EpollEventLoop@652a7737) 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO HTTP request: 2024-11-21 02:17:42,821 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 02:17:42,821 INFO headers: 2024-11-21 02:17:42,821 INFO accept: application/json 2024-11-21 02:17:42,821 INFO content-type: application/json 2024-11-21 02:17:42,821 INFO user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/17.17134 2024-11-21 02:17:42,821 INFO X-Forwarded-For: 42.42.42.42 2024-11-21 02:17:42,821 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 02:17:42,821 INFO content-length: 0 2024-11-21 02:17:42,821 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO HTTP response: 2024-11-21 02:17:42,821 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 02:17:42,821 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 02:17:42,821 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 02:17:42,821 INFO Request: 2024-11-21 02:17:42,821 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO Session: 2024-11-21 02:17:42,821 INFO Session(idc.benchmark.Mix2024,501401,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.30, randomPolicyName -> testPolicy354977, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@3519a12, fake-user-agent -> Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1, password -> Pa_ssw0rd, fake-ip -> 223.212.170.168, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@a014fe3),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007cd850698000@23fc68bc,io.netty.channel.epoll.EpollEventLoop@5b7ea70d) 2024-11-21 02:17:42,821 INFO ========================= 2024-11-21 02:17:42,821 INFO HTTP request: 2024-11-21 02:17:42,821 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 02:17:42,821 INFO headers: 2024-11-21 02:17:42,821 INFO accept: application/json 2024-11-21 02:17:42,821 INFO content-type: application/json 2024-11-21 02:17:42,821 INFO user-agent: Mozilla/5.0 (iPhone; CPU iPhone OS 13_2_3 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0.3 Mobile/15E148 Safari/604.1 2024-11-21 02:17:42,822 INFO X-Forwarded-For: 223.212.170.168 2024-11-21 02:17:42,822 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 02:17:42,822 INFO content-length: 0 2024-11-21 02:17:42,822 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 02:17:42,822 INFO ========================= 2024-11-21 02:17:42,822 INFO HTTP response: 2024-11-21 02:17:42,822 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 02:17:42,822 INFO 02:16:20.583 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 02:17:42,822 INFO 02:16:20.583 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 02:17:42,822 INFO 02:16:20.583 [DEBUG] i.g.h.e.r.DefaultStatsProcessor - 2024-11-21 02:17:42,822 INFO >>>>>>>>>>>>>>>>>>>>>>>>>> 2024-11-21 02:17:42,822 INFO Request: 2024-11-21 02:17:42,822 INFO restLoginInitiate: KO j.i.IOException: Premature close 2024-11-21 02:17:42,822 INFO ========================= 2024-11-21 02:17:42,822 INFO Session: 2024-11-21 02:17:42,822 INFO Session(idc.benchmark.Mix2024,501397,HashMap(gatling.http.cache.baseUrl -> https://openam-perf-benchmark.forgeblocks.com:443, username -> user.161303, gatling.http.ssl.sslContexts -> io.gatling.http.util.SslContexts@1aec0b94, fake-user-agent -> Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36, password -> Pa_ssw0rd, fake-ip -> 42.42.42.42, gatling.http.cache.dns -> io.gatling.http.resolver.ShufflingNameResolver@6c24d5fc),KO,List(),io.gatling.core.protocol.ProtocolComponentsRegistry$$Lambda$823/0x00007cd850698000@23fc68bc,io.netty.channel.epoll.EpollEventLoop@619bfe29) 2024-11-21 02:17:42,822 INFO ========================= 2024-11-21 02:17:42,822 INFO HTTP request: 2024-11-21 02:17:42,822 INFO POST https://openam-perf-benchmark.forgeblocks.com/am/json/realms/root/authenticate 2024-11-21 02:17:42,822 INFO headers: 2024-11-21 02:17:42,822 INFO accept: application/json 2024-11-21 02:17:42,822 INFO content-type: application/json 2024-11-21 02:17:42,822 INFO user-agent: Mozilla/5.0 (Linux; Android 8.0.0; Pixel 2 Build/OPD3.170816.012) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.85 Mobile Safari/537.36 2024-11-21 02:17:42,822 INFO X-Forwarded-For: 42.42.42.42 2024-11-21 02:17:42,822 INFO host: openam-perf-benchmark.forgeblocks.com 2024-11-21 02:17:42,822 INFO content-length: 0 2024-11-21 02:17:42,822 INFO body:StringChunksRequestBody{charset=UTF-8, content=} 2024-11-21 02:17:42,822 INFO ========================= 2024-11-21 02:17:42,822 INFO HTTP response: 2024-11-21 02:17:42,822 INFO <<<<<<<<<<<<<<<<<<<<<<<<< 2024-11-21 02:17:42,822 INFO 02:16:20.583 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-104' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 02:17:42,822 INFO 02:16:20.583 [ERROR] i.g.c.a.b.SessionHookBuilder$$anon$1 - 'hook-163' crashed with 'j.u.NoSuchElementException: No attribute named 'callbacks' is defined', forwarding to the next one 2024-11-21 02:17:42,822 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 02:17:42,822 INFO [INFO] BUILD SUCCESS 2024-11-21 02:17:42,822 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 02:17:42,822 INFO [INFO] Total time: 01:00 h 2024-11-21 02:17:42,822 INFO [INFO] Finished at: 2024-11-21T02:16:21Z 2024-11-21 02:17:42,822 INFO [INFO] ------------------------------------------------------------------------ 2024-11-21 02:17:42,822 INFO 2024-11-21 02:16:21,079 INFO Gatling simulation run ended successfully 2024-11-21 02:17:42,822 INFO 2024-11-21 02:16:21,079 DEBUG No archive name provided. No archive will be created 2024-11-21 02:17:42,822 INFO ________________________________________________________________________________ [2024-11-21 02:17:42] benchmark-140 show_stderr : Display stderr order ________________________________________________________________________________ 2024-11-21 02:17:42,823 DEBUG [print_head_tail]: Input file /mnt/disk1/xslou/workshop/lodestar-fork/results/pyrock/idc_benchmark/07_Scenario_benchmark/07_benchmark-140/stderr.txt is small (0 lines), printing all lines: 2024-11-21 02:17:42,823 DEBUG ----- output ----- 2024-11-21 02:17:42,823 DEBUG 2024-11-21 02:17:42,823 INFO ________________________________________________________________________________ [2024-11-21 02:17:42] benchmark-140 check_rc_and_logs : Check order's outputs ________________________________________________________________________________ PASS: no error found in rc log PASS: no error found in stdout log PASS: no error found in stderr log ________________________________________________________________________________ [2024-11-21 02:18:07] benchmark-140 print_overseer_logs : Print overseer logs from the K8s pod ________________________________________________________________________________ Task result is INIT no need to display logs. ________________________________________________________________________________ [2024-11-21 02:18:07] benchmark-140 post : Post ________________________________________________________________________________ Setting result to PASS Task has been successfully stopped