# πŸ“ˆ ProfilingΒ² with Qryn Adventures pt. 1 [![](https://cdn.hashnode.com/res/hashnode/image/upload/v1725387322397/4048aecc-61f2-482a-938b-9155c99230d5.png align="center")](https://qryn.dev) **Profiling** performance will take you places - *and at times* - the improvement process can spin off into quite interesting journeys often leading to *unexpected results. Performance tuning is one of significant parts for qryn development,* and we are extremely proud of being able to do it using [qryn](https://qryn.dev) itself! ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1725748680993/76aa317a-a0bc-41a2-bd0c-b83d310dfd11.gif align="center")
πŸ’‘
Check our Pyroscope Continuous Profiling announcement πŸ”₯πŸ”₯πŸ”₯πŸ”₯
![](https://cdn.hashnode.com/res/hashnode/image/upload/v1725391051656/e5a773d2-d5ff-4ce5-b899-cd611ddb5770.png align="center") Today we'll share a small sample from our development experience in using [PGO](https://go.dev/doc/pgo) to optimize the qryn [Opentelemetry](https://github.com/metrico/otel-collector) collector performance. Through the article, we'll examine the effectiveness of [PGO](https://go.dev/doc/pgo) and analyze the results of our profiling exercise using [qryn](https://qryn.dev) to explore the practical implications of this optimization technique. ### Application Benchmark Setup In order to perform our optimization and demonstrate the results, *we need an application to optimize*. The application should be under a constant load for a significant amount of time *(the longer, the better; let's say at least 20 minutes)*. ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1725388470542/04c28b7f-fc2c-4f16-bf97-ed18dc98d3e9.png align="center") We will use the **Pyroscope** client to collect the profile data and some readers to access the collected profiles. We will run an [Opentelemetry](https://github.com/metrico/otel-collector) collector accepting application profiles through the **Pyroscope-compatible API** and saving them directly into the [qryn](https://qryn.dev) database. The running [Opentelemetry](https://github.com/metrico/otel-collector) collector features a **Pyroscope** extension that sends its own profiles to the accepting endpoint described earlier. ***Thus, in this specific example, the collector will profiles itself*** πŸ”₯ Apart from the [Opentelemetry](https://github.com/metrico/otel-collector) collector, we will leverage a [qryn](https://qryn.dev) instance reading from the same database and a Grafana instance providing the user interface to read the saved profiles. *Let's start our profiling exercise!* ![20 Minutes Later | Spongebob Time Cards](https://i.ytimg.com/vi/XtdpaLnVtAA/hq720.jpg?sqp=-oaymwEhCK4FEIIDSFryq4qpAxMIARUAAAAAGAElAADIQj0AgKJD&rs=AOn4CLBFI6A9tpmeH8OV2vthPmsTWgRxSw align="left") # PGO optimization of the Collector This example optimization process will be quite simple: 1. Wait for 10-20 minutes to collect a sufficient amount of **pprof** data. 2. Merge the collected **pprof** observations into one result pprof. 3. Add a `-pgo pgo.pprof` flag to the `go build` directive to build the optimized application. Let's begin by analyzing the outcome of our first step: ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1724952400402/f28be144-e616-41f6-9ff9-4bc9545849c2.png align="center") The results are quite clear and easy to understand: * About 50% of the time was taken by the Go garbage collector (GC) * `runtime.mca...` is likely the HTTP server * `(4) go.opente` is the qryn exporter writing to the qryn database * [`github.com/`](http://github.com/) is the Pyroscope client itself Next, let's try to combine the intermediate **pprofs** using the [**profilecli**](https://grafana.com/docs/pyroscope/latest/view-and-analyze-profile-data/profile-cli/) tool: ```bash $ profilecli query merge \ --from='2024-08-27T15:37:45+03:00' \ --to='2024-08-27T16:00:30+03:00' \ --url=http://localhost:3100 | head -n 10 level=info msg="query aggregated profile from profile store" url=http://localhost:3100 from=2024-08-27T15:37:45+03:00 to=2024-08-27T16:00:30+03:00 query={} type=process_cpu:cpu:nanoseconds:cpu:nanoseconds PeriodType: cpu nanoseconds Period: 10000000 Time: 2024-08-27 15:37:55.600057479 +0300 EEST Duration: 22m4 Samples: samples/count cpu/nanoseconds 4 40000000: 1 2 3 4 5 6 2 20000000: 7 8 9 10 11 12 13 2 20000000: 14 15 16 17 18 5 6 2 20000000: 19 20 21 22 23 24 25 26 27 $ profilecli query merge \ --from='2024-08-27T15:37:45+03:00' \ --to='2024-08-27T16:00:30+03:00' \ --url=http://localhost:3100 \ --output=pprof=./pgo.pprof level=info msg="query aggregated profile from profile store" url=http://localhost:3100 from=2024-08-27T15:37:45+03:00 to=2024-08-27T16:00:30+03:00 query={} type=process_cpu:cpu:nanoseconds:cpu:nanoseconds $ ls -la | grep pgo.pprof -rw-r--r-- 1 user user 30324 сСр 29 20:42 pgo.pprof ```
πŸ’‘
A fresh 30kB pprof file is generated by the above profilecli operation
Since we mostly use a **dockerized opentelemetry** collector to run our test we can simply add the `-pgo` flag to the **Dockerfile** and build it: ```bash $ cat cmd/otel-collector/Dockerfile # Builder stage FROM golang:1.22.1-alpine as builder RUN apk --update add ca-certificates # ... RUN cd cmd/otel-collector && \ go build -pgo=/src/pgo.pprof -tags timetzdata -o /out/otel-collector # Final stage FROM scratch # ... ENTRYPOINT ["/otel-collector"] CMD ["--config", "/etc/otel/config.yaml"] $ docker build \ -t otel-collector:latest \ -f cmd/otel-collector/Dockerfile . [+] Building 61.5s (13/13) FINISHED docker:default => [internal] load build definition from Dockerfile 0.1s => => transferring dockerfile: 579B 0.0s => WARN: FromAsCasing: 'as' and 'FROM' keywords' casing do not match (line 2) 0.1s => [internal] load metadata for docker.io/library/golang:1.22.1-alpine 1.6s ... => => naming to docker.io/library/otel-collector:latest 0.0s ```
πŸ’‘
Note: the full example Dockerfile can be found on our github repository
Let's repeat our test and wait for another 20 minutes and check the results... ![20 Minutes Later | Spongebob Time Cards](https://i.ytimg.com/vi/XtdpaLnVtAA/hq720.jpg?sqp=-oaymwEhCK4FEIIDSFryq4qpAxMIARUAAAAAGAElAADIQj0AgKJD&rs=AOn4CLBFI6A9tpmeH8OV2vthPmsTWgRxSw align="left") # Results of the Optimization *According to most blog articles, PGO typically yields a 2-7% improvement.* *Initially, we want to debunk how multiple iterations could potentially improve the application's performance several times (spoiler alert: they do not)* To find out we performed two iterations of the process and compared results: ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1724954887655/defee765-9626-469f-9e7c-d2f384f59ddb.png align="center") Both charts represent 20 minutes span of observation, with the application under constant load. The comparison between Base and First Round of optimization shows promising results: an improvement of `(1-(4.66/4.94))*100=5.67%`. However, as suspected, the Second Round yielded less optimistic results: ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1724955280015/1a7240ce-cc4a-45ed-9405-f82db9577779.png align="center") πŸ›‘ The comparison of **4.94s** vs **4.97s** shows `(1-(4.94/4.97))*100=0.6%` downgrade We can conclude that the second round performance is similar *(if not slightly worse)* to the baseline measurement. This easily demonstrates that there's definitely lots of value in PGO but also no such thing as infinite optimization and no speed of light :) The most viable strategy for **PGO** usage: 1. Provide a benchmark of the *unoptimized* Go application. 2. Observe performance using the **Pyroscope** client and [**qryn**](https://qryn.dev)**.** 3. Save the resulting **pprof** for **PGO** needs periodically. # Other notices during the comparison Contrary to my expectations based on articles about PGO, which suggested it would *"trim the noodles"* on the **flamechart** by in-lining some functions into their callers, it sometimes does quite the opposite: ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1724956122596/c6ae2e06-aa89-4fe4-b94d-1d042ea2cd69.png align="center") *(left is baseline, right is optimized)* Next: let's take things a step further and examine the **diff view** supported in [**qryn**](https://qryn.dev) since the latest **3.2.29** version. > Hey, did we mention how we're using ONLY [**qryn**](https://qryn.dev) and **NOT Pyroscope** to run this test? 😏 We're so proud of our polyglot API supporting Continuous Profiling! ## Pyroscope diff view ![](https://cdn.hashnode.com/res/hashnode/image/upload/v1724957434439/b57a6c63-31bb-4c55-9637-dde574a7b726.png align="center") Well, obviously, the most improved parts are GC *(Garbage Collection)* and the **runtime.mcall** HTTP server. **PGO** definitely *"trimmed some noodles"* there (dark green color in the mid GC part). The rest of the chart needs further investigation. The **Pyroscope** diff view is not very intuitive to read. The main downside I see is that they use percent comparison to represent color. Let's consider an example: Suppose John, Mike, and I had 2 apples each. We had 6 apples overall, and each of us had 33% of all apples. Then one of my apples was "optimized" out. Now we have 5 apples. John and Mike have 40% each, and I have just 20%. * Have my apples been optimized? Yes, and my part will be green on the chart. * Have John's and Mike's apples been downgraded? No, they still have 2 apples each. But their parts will be red because their percent stake in increased by 10%. With this in mind, we should read the diff view as follows: * green is definitely green * bright red is definitely bright red * faded red may be grey or green * grey may be green During the comparison process, at some point, I came up with an average determiner of the profile: `/