We are living in a container world and I am a container boy. Okay, so maybe a modified version of Madonna's Material Girl does not come to mind right away. However with more and more workloads moving to containers and their orchestration in Kubernetes, Liberty performance needs to be tracked regularly and optimized explicitly for these new environments. In this blog, I would like to share how the WebSphere Performance Engineering Team measures how containerization impacts startup, first response, and footprint. Reasons why these metrics are necessary:
- application changes (features, bug fixes, security updates etc.)
- runtime option changes (increase or decrease heap, etc.)
- new dependencies on any layer (application, application server, etc.)
- resource changes or constraints (more memory, less cpu, etc.)
All of these can have an effect on all three of our metrics or affect them independently.
To provide a more concrete frame of reference, we need docker, open-liberty, and our application, "Trade7". Our computer is a single socket with 16 CPUs (0 - 15) represented by the output of the command, lscpu | grep NUMA.
NUMA node(s): 1
NUMA node0 CPU(s): 0-15
We build our container of Open Liberty and our application and then start it using docker run -d -p 9080:9080 --cpuset-cpus="10-13" --memory=4g --name trade7 open-liberty/trade7. It should return the Container ID on exit. Please notice that I have specified the --name in the docker run command. This allows us to alias it for later commands. Also I have bound docker to CPUs 10 - 13. These numbers are inclusive, so that's 4 CPUs and 4 GB of memory for this container.
Before we mention caveats in the environment, let’s provide some distinct definitions of startup, footprint, and first response and how they are measured. We measure startup in two ways. The first measurement is the elapsed time from the start of the container to when the application server has completed its initialization. In Docker, the specific command we have used comes from docker inspect and docker ps, docker inspect --format='{{.State.StartedAt}}' $(docker ps --format='{{.ID}}' -f "name=trade7") | awk '{gsub("T", " "); print substr($0, 1, length($0)-6)}'. This command gets the "Container ID" filtering on our alias, "trade7" then passes that "Container ID" to docker inspect command. Finally we pipe it through awk to format the date, leaving the milliseconds. Below is a sample output.
2021-10-11 19:46:55.3013
In Liberty, this is noted by the log entry “The defaultServer server is ready to run a smarter planet. The defaultServer server started in […] seconds.” We capture the timestamp from the logs using docker exec $(docker ps --format='{{.ID}}' -f "name=trade7") grep is ready to run a smarter planet." /logs/messages.log | awk '{ gsub("\\[", "", $1); gsub(",", "", $1); print $1 " " gensub(":", ".", 3, $2)}' | { read -r output; date -u +'%F %T.%3N' -d "$output"; }. Similar to our previous docker inspect command, we get our "Container ID" from docker ps then pass that to docker exec to grep on the log file to get the timestamp. Below is a sample output.
2021-10-11 19:46:56.415
The second measurement is the elapsed time from the start of the application server to when the application server has completed its initialization. We have the time when the server finished. The start of the application server is noted by the log entry, “The server defaultServer has been launched.” To get our start of Liberty, we use the command, docker exec $(docker ps --format='{{.ID}}' -f "name=trade7") grep " has been launched." /logs/messages.log | awk '{ gsub("\\[", "", $1); gsub(",", "", $1); print $1 " " gensub(":", ".", 3, $2)}' | { read -r output; date -u +'%F %T.%3N' -d "$output"; }. Below is a sample output.
2021-10-11 19:46:55.657
We now have docker start, liberty start, and liberty finish. Below is a small table with our times.
- Docker – Start: 2021-10-11 19:46:55.3013
- Liberty – Start: 2021-10-11 19:46:55.657
- Liberty – Finish: 2021-10-11 19:46:56.415
- Application (First) Response
We are still missing our first response. I mentioned earlier about "caveats in the environment". We want to avoid launching the load driver sending the first request on the same CPU as our docker container. This is why the curl command is preceded by the "taskset command. We bind curl to CPUs 2 and 3. Also, in our application "Trade7", we have an endpoint that we curl to return an HTTP 200 response. Below is something that would get executed that's akin to our example here.
while [[ "$(taskset -c 2-3 curl -s -o /dev/null -w ''%{http_code}'' 127.0.0.1:9080/trade7/servlet/PingServlet)" != "200" ]]; do
sleep 0.001;
done
firstResponse=$(date -u +'%F %T.%3N')
We calculate first response using two methods. The reason for two methods provides us with how much slower The first methods gives us our first response from the start of the docker container to the response of the application. This calculates the time between the container start time and an HTTP 200 response from the app inside the application server. The second methods gives us our first response from the start of Liberty to the response of the application. This calculates from the launch of the application server to the HTTP 200 response from the app. This should fill in our last number that we need to calculate startup and first response.
- Docker – Start: 2021-10-11 19:46:55.3013
- Liberty – Start: 2021-10-11 19:46:55.657
- Liberty – Finish: 2021-10-11 19:46:56.415
- First Response: 2021-10-11 19:46:56.923
Our last metric, footprint, is captured using docker stats. In our example, that command would be docker stats $(docker ps --format='{{.ID}}' -f "name=trade7") --no-stream --format='{{.MemUsage}}' | awk '{print $1}''. This command is executed after our first response is captured. The output of this command is in megabytes: 74.01.
Here are the final values we can use to compare to previous regression tests.
- Docker Startup: 1114 ms
- Docker First Response: 1619 ms
- Liberty Startup: 758 ms
- Liberty First Response: 1263 ms
- First response Footprint: 74.01 MB
In summary, WebSphere Performance uses startup, first response, and footprint to monitor for regressions and how containers may affect our applications. This ensures Liberty is performing efficiently and changes to the software do not regress customer performance.
#websphere-performance #containers #Liberty #OpenLiberty
#WebSphere-performance
#performance
#containers