Forem: Viacheslav Poturaev

Finding a Practical Analytics Format for Structured JSON Logs

Viacheslav Poturaev — Thu, 23 Apr 2026 17:01:17 +0000

Structured JSON logs are easy to produce and hard to analyze at scale. They carry useful context, but that context is nested, optional, inconsistent, and often wider than expected. Before the data can be queried comfortably, it usually has to become a table.

The question is not only "can we flatten it?" The more useful question is:

After flattening, what should the output be?

CSV is simple and fast. Parquet is compact and portable. DuckDB gives a ready-to-query local database. SQLite is widely available. Direct database APIs look convenient from Go, but may not behave like bulk loaders.

This note walks through a small discovery process: define realistic shapes, run the same flattening flow through several output types, and compare write/export cost plus resulting artifact size.

The Contestants

The tested output types were:

CSV file: plain text table output, the simplest baseline.
Parquet Snappy: portable columnar file with fast compression.
Parquet Zstd: portable columnar file with stronger compression.
DuckDB CLI stdin: stream CSV into the duckdb CLI and create a database table. This path relies on DuckDB's CSV reader with automatic type detection rather than a hand-declared schema.
SQLite CLI import: stream CSV into the sqlite3 CLI and create a database table.
SQLite direct inserts: write rows through the Go SQLite driver.
DuckDB native appender experiment: write rows through a native DuckDB Go appender driver.

The CLI output types matter because they behave like bulk loaders. They let flatjsonl focus on flattening and streaming rows, while the database process handles ingestion in its optimized path.

The `flatjsonl` Flow

flatjsonl uses two passes:

Scan the input to discover keys and infer column types.
Read the input again, flatten each JSON object, and write rows to the chosen output.

The first pass is mostly independent of output format. For comparing CSV, Parquet, SQLite, and DuckDB, the second pass is more interesting: it includes flattening, value conversion, writing/importing, compression, and finalization.

So the main timing metric below is Export time:

Export time = total wall time - key scan time

This intentionally ignores the common discovery pass and focuses on the output-side cost.

The Data Shapes

Flattened JSON performance depends heavily on shape. Three patterns were used:

Pattern	Rows	Result Columns	Type Mix	Shape
Narrow	5691804	23	Mostly strings, a few bools and ints.	Small reporting extract: low/medium-cardinality dimensions, one numeric measure, and status flags.
Normal	5691804	118	String-heavy with more ints and bool flags.	Practical analytics extract: request metadata, timestamps, dimensions, numeric measures, duration windows and flags.
Wide	193217	about 1680	Mostly optional strings and sparse dimensions, with some ints/bools/floats.	Stress case for rich nested JSON logs with many rarely-populated and high-cardinality columns.

The exact field names are not important here. The important properties are row count, column count, type mix, string cardinality, sparse optional fields, and how much text has to move through the writer.

All numbers are approximate. These are production-shaped samples rather than controlled synthetic fixtures. The goal is to build intuition about tradeoffs.

Reading The Results

The tables use relative cost indexes.

100% is the best measured result in that scenario. Higher is worse.

For example:

250% write/export time means about 2.5x slower than the fastest path for that data shape.
250% artifact size means about 2.5x larger than the smallest artifact for that data shape.

Write/Export Time

This table excludes key scanning and focuses on flattening plus writing/importing.

Output	Narrow	Normal	Wide
CSV file	`100%`	`100%`	`100%`
Parquet, Snappy	`102%`	`130%`	`253%`
Parquet, Zstd	`103%`	`142%`	`289%`
DuckDB CLI stdin	`103%`	`199%`	`384%`
SQLite CLI CSV import	`103%`	`246%`	`596%`
SQLite direct inserts	`130%`	`534%`	`2932%`
DuckDB native appender (experimental)	`253%`	`1089%`	`2440%`

The fastest absolute export times were:

Pattern	Best Output	Best Export Time
Narrow	CSV file	`35.1s`
Normal	CSV file	`35.9s`
Wide	CSV file	`10.6s`

The narrow case is almost flat: CSV, Parquet, DuckDB CLI, and SQLite CLI are all within a few percent. In the normal and wide cases, writer choice starts to matter.

Artifact Size

This table compares resulting file/database size.

Output	Narrow	Normal	Wide
CSV file	`828%`	`635%`	`264%`
Parquet, Snappy	`156%`	`138%`	`122%`
Parquet, Zstd	`100%`	`100%`	`101%`
DuckDB CLI stdin	`113%`	`141%`	`100%`
SQLite CLI CSV import	`901%`	`708%`	`280%`
SQLite direct inserts	`901%`	`670%`	`274%`
DuckDB native appender (experimental)	`212%`	`177%`	`130%`

The winners were:

Pattern	Smallest Path	Size
Narrow	Parquet, Zstd	`90M`
Normal	Parquet, Zstd	`502M`
Wide	DuckDB CLI stdin	`732M`

CSV wins on write speed, but it is consistently large. Compressed Parquet and DuckDB are much more storage-efficient.

The native DuckDB appender path was an experiment, not the final export implementation. Its database schema was not identical to the CLI path: it included an extra sequence primary key and used less precise types for some fields. Treat its size and time as a cautionary data point for row-wise appender ingestion, not as a tuned DuckDB baseline.

The size gap is also a useful reminder that DuckDB is columnar. Physical size is sensitive to column types, compression opportunities, and how data is loaded. SQLite behaved differently in the same experiment: CLI import and direct inserts produced similarly sized files even when their declared schemas differed, because SQLite stores row records with dynamic typing rather than compressed column segments.

Sample Analytical Query

Export speed is only half of the story. The point of making a table is usually to query it.

As a small read-side check, I ran a grouped count over one string dimension:

SELECT count(1), os_name
FROM flatjsonl
GROUP BY os_name
ORDER BY count(1);

For CSV and Parquet, DuckDB queried the files directly. They were not imported into a database first. SQLite databases were queried with sqlite3.

These timings are single local runs and should be read as rough order-of-magnitude results.

No indexes were created for this query. That is intentional: the goal is to compare raw analytical scan behavior of the artifacts as produced by the export step. Adding indexes, especially to SQLite or DuckDB tables, could change query performance drastically for selective filters or repeated lookups. At that point the benchmark would be measuring index design and maintenance cost rather than the default export artifact.

Cells show relative query cost and absolute time. Percentages are normalized independently down each data-shape column, because the datasets differ in row count, width, and value distribution. 100% is the fastest result in that column, and higher percentages are slower.

Output	Narrow	Normal	Wide
CSV via DuckDB direct scan	`600% / 0.36s`	`2860% / 1.43s`	`9800% / 3.92s`
Parquet Snappy via DuckDB	`200% / 0.12s`	`240% / 0.12s`	`1700% / 0.68s`
Parquet Zstd via DuckDB	`167% / 0.10s`	`260% / 0.13s`	`1675% / 0.67s`
DuckDB database	`100% / 0.06s`	`100% / 0.05s`	`125% / 0.05s`
SQLite CLI database	`3750% / 2.25s`	`8360% / 4.18s`	`13450% / 5.38s`
SQLite direct database	`4217% / 2.53s`	`9180% / 4.59s`	`14250% / 5.70s`
DuckDB native appender database	`100% / 0.06s`	`100% / 0.05s`	`100% / 0.04s`

This query is favorable to columnar formats: it touches one dimension column and computes a small aggregation. DuckDB database files and Parquet are very fast. CSV has to parse text again and gets slower as the file gets wider/larger. SQLite is functional, but slower for this analytical scan.

The wide result highlights an important distinction: Parquet is columnar, but it is still an external file format. DuckDB can query it efficiently, but it still has to read Parquet metadata, decode Parquet pages and adapt the data into DuckDB execution vectors. A DuckDB database is already in DuckDB's native storage layout, with its own column segments, compression, statistics and execution-friendly metadata. For repeated DuckDB queries, especially ones touching a tiny subset of a very wide table, the native database can be noticeably faster even when Parquet is also columnar.

I also repeated the query with a second dimension that has noticeably higher cardinality than a very low-cardinality first field (os_name):

SELECT count(1), os_name, country
FROM flatjsonl
GROUP BY os_name, country
ORDER BY count(1);

This makes every path slower than the earlier one-field query, but the overall ranking stays the same. Row-oriented databases pay much more once the grouping key widens from one dimension to two.

Output	Narrow	Normal	Wide
CSV via DuckDB direct scan	`370% / 0.37s`	`1567% / 1.41s`	`5113% / 4.09s`
Parquet Snappy via DuckDB	`160% / 0.16s`	`167% / 0.15s`	`975% / 0.78s`
Parquet Zstd via DuckDB	`150% / 0.15s`	`178% / 0.16s`	`975% / 0.78s`
DuckDB database	`100% / 0.10s`	`100% / 0.09s`	`100% / 0.08s`
SQLite CLI database	`4110% / 4.11s`	`7078% / 6.37s`	`7138% / 5.71s`
SQLite direct database	`3990% / 3.99s`	`6844% / 6.16s`	`7488% / 5.99s`
DuckDB native appender database	`100% / 0.10s`	`100% / 0.09s`	`100% / 0.08s`

DuckDB stayed surprisingly fast even after widening the grouping key. The likely reason is that the query still touches only a tiny subset of the table: two projected dimension columns plus the row count. In a columnar, vectorized engine, adding one more grouped column is much cheaper than widening a row-store scan across the full record. The query does get slower, but not dramatically, because it still reads only a few columns and the resulting group count remains manageable.

What The Shapes Teach

Narrow

The narrow shape has only 23 columns. Most values are short strings with low or medium cardinality, plus one numeric measure and a few boolean flags.

For this shape, output choice barely affects write/export time. The data pass itself dominates. CSV, Parquet, DuckDB CLI, and SQLite CLI all finish in the same practical range.

Artifact size still changes dramatically. CSV and SQLite are roughly 8-9x larger than Zstd Parquet. DuckDB CLI and Zstd Parquet are both compact enough that the choice mainly depends on whether the desired result is a database file or a portable columnar file.

Normal

The normal shape has 118 columns. It is still string-heavy, but it includes enough numeric measures, duration/window fields, timestamps, request metadata, and boolean flags to look like a practical operational analytics table.

This is where writer cost becomes visible. CSV remains fastest, but produces a very large artifact. Parquet Snappy adds moderate overhead and cuts size substantially. Parquet Zstd costs a bit more time and gives the smallest file.

DuckDB CLI is slower than Parquet, but it creates a ready-to-query database in one step. SQLite CLI remains workable, but its size and write cost are less attractive. Direct row-wise database APIs are already a poor fit.

Wide

The wide shape has fewer rows but about 1680 columns. It is sparse and string-heavy: optional identifiers, free-form strings, long text fields, and nested dimensions dominate the schema. Numeric and boolean fields are mixed in, but they are not what makes the workload difficult.

This is where format and ingestion path dominate. Parquet costs more CPU than CSV, but cuts storage substantially. DuckDB CLI produces the smallest measured artifact and avoids a separate import step, but costs more write/export time than Parquet.

SQLite CLI is much faster than direct SQLite inserts, but still slow and large compared with Parquet or DuckDB. Direct row-wise database APIs spend too much time crossing driver boundaries, converting values, appending/binding thousands of cells per row, and managing memory.

Practical Conclusions

Use CSV when the main goal is fastest raw export and temporary text output is acceptable.

Use Parquet Snappy as the default portable analytics artifact. It is much smaller than CSV and has acceptable write overhead for narrow and normal shapes.

Use Parquet Zstd when storage or transfer size matters more than a bit of extra CPU.

Use DuckDB CLI when the desired output is directly a DuckDB database. It is competitive on import across narrow, normal, and wide shapes, and then gives excellent query performance once the data is loaded. In these experiments it was especially strong for analytical scans that touched only a small subset of columns.

Use SQLite CLI when SQLite compatibility is required. Prefer CLI bulk loading over direct inserts.

Avoid direct row-wise database insertion for uncertain production JSON shapes unless the dataset is small or the schema is known to stay narrow.

The broader lesson is that "structured logs" are not one benchmark. Row count, column count, string cardinality, sparse optional fields, and output format all matter. For exploratory analytics at scale, the safest default is to produce a portable columnar artifact first, and only create a database file directly when that is the actual target.

Publishing Markdown to Confluence using GitHub Actions

Viacheslav Poturaev — Wed, 21 Feb 2024 23:30:11 +0000

TL;DR We're going to setup automated Markdown export from a GitHub repository to Confluence to benefit from knowledge locality in a centralized storage.

Markdown is a lightweight markup language for creating formatted text using a plain-text editor.

https://en.wikipedia.org/wiki/Markdown

With the growing popularity of GitHub and other code hosting services, Markdown has become widely used as a language for documentation. It is very convenient to keep nicely formatted documentation close to the code it describes.

While Markdown in code repositories may lack advanced features such as search index or rich web components, it has the advantages of simplicity, lower chance of becoming obsolete and clear versioning.

With the addition of support for mermaid diagrams in GitHub, Markdown has become a very powerful tool for versioned and accurate documentation.

In contrast, Atlassian Confluence acts as a centralized repository of information, often used by large organizations to share knowledge across people and departments. There are advantages to such an approach; access control and discoverability may be better. For example, access to code repositories is usually given to developers who work with it, not to people who support users of the product.

However, Confluence often becomes an information graveyard. As the codebase evolves, pages become obsolete or even misleading.

Could you have the best of both worlds? The answer is "Yes"!

We can organize the source of truth for code-related documents into Markdown files that live in code repositories, and then automatically sync changes to Confluence using GitHub Actions.

There is a markdown-confluence tool and a GitHub action around it that makes the export process much easier than it could have been.

Let's take an example repo and configure export of OpenAPI documentation and handwritten README.md into Confluence.

First thing to do is to get an API token. If you have enough permissions, you can create one at your profile page, otherwise you'll probably need to contact a person that manages your Confluence.

Then you need to provide credentials to GitHub Actions with repository secrets, use email for ATLASSIAN_USERNAME and API token for ATLASSIAN_API_TOKEN.

I have a toy service that I used for one of my previous posts. It has a GitHub Action workflow to keep the OpenAPI documentation up to date on a GitHub wiki page.



...
      - name: Checkout wiki
        uses: actions/checkout@v2
        with:
          repository: ${{github.repository}}.wiki
          path: wiki
      - name: Build openapi.json
        run: |
          make build
          ./bin/* -openapi > openapi.json
          cat ./openapi.json
      - name: Generate markdown docs
        uses: docker://swaggest/swac
        with:
          args: /bin/sh -c "swac markdown ./openapi.json --add-schema-url openapi.json --out ./wiki/API-Docs.md;mv -f ./openapi.json ./wiki/openapi.json"
      - name: Push to wiki
        run: |
          cd wiki
          git config --local user.email "action@github.com"
          git config --local user.name "GitHub Action"
          git add .
          git diff-index --quiet HEAD || git commit -m "Add changes" && git push

Let's upgrade this workflow to push a document to Confluence.

NOTE: Official doc has a misleading suggestion of markdown-confluence/publish@v1, workflow fails with
Error: Unable to resolve action markdown-confluence/publish, repository not found
markdown-confluence/publish-action@v5 works well.



      - name: Publish Markdown to Confluence
        uses: markdown-confluence/publish-action@v5
        with:
          confluenceBaseUrl: https://vearutop.atlassian.net
          confluenceParentId: 65538
          folderToPublish: wiki
          atlassianUserName: ${{ secrets.ATLASSIAN_USERNAME }}
          atlassianApiToken: ${{ secrets.ATLASSIAN_API_TOKEN }}

Unfortunately, the result wasn't that great, Markdown flavors are different between GitHub and Confluence.

Confluence doesn't allow manual anchoring with



## <a id="operations"></a> Operations

Instead, it expects local anchors to be in form of urlencoded value with some filtering (spaces are replaced by hyphens, backticks are removed).

Also, headers within list items are not supported. Making a spoiler with <details> does not work either. These are the few things I found while experimenting with Confluence export.

Once I've updated OpenAPI Markdown generator to accommodate for these quirks, the result was much better. The list was rendered correctly, local links to schema definitions started working.

Now I'd like to publish a page with some images and diagrams. README.md of the repo is a good candidate. It has both images and mermaid diagrams.

Result is surprisingly good, images are displayed,

mermaid diagrams too (though rendered as PNG).

Spoiler didn't work.

GitHub Action to publish Markdown to Confluence accepts path to directory with .md files. If you need to publish under a different parent id, you'll probably need to build a directory structure and invoke publishing with different configurations as separate steps.

Here is a final example workflow.

Building a portable face recognition application with Go and dlib

Viacheslav Poturaev — Thu, 01 Feb 2024 13:43:08 +0000

TL;DR We're going to build a portable facial recognition microservice for Linux using static linker in Go build with CGO dependencies.

One of the great things about Go is portability of applications built with it.

You can build a binary for different platforms and run it without installing any dependencies on the target machine. This becomes especially important if such a machine is an older low-end server with limited resources that would struggle to build an app or install needed shared libraries.

Building static apps is easy when all code is in Go, but it can become more complicated with CGO dependencies.

Davis King has made an awesome C++ dlib library, that can efficiently detect people faces in a photo. Kagami Hiiragi built a go-face library that allows using dlib from a Go application.

The installation guide mentions a few dependencies needed for a successful build:

sudo apt-get install libdlib-dev libblas-dev libatlas-base-dev liblapack-dev libjpeg-turbo8-dev

By default, the build will depend on shared libraries and then, if you try to run the resulting binary somewhere else, it may fail due to missing file, like here:

./faces: error while loading shared libraries: libdlib.so.19: cannot open shared object file: No such file or directory

Linux has an ldd tool to inspect binary dependencies, most common problems when you try to run a binary built on another Linux machine are version mismatch of GLIBC and missing libraries.

ldd ./faces
./faces: /usr/lib/x86_64-linux-gnu/libstdc++.so.6: version `GLIBCXX_3.4.26' not found (required by ./faces)
    linux-vdso.so.1 (0x00007fff871b5000)
    libdlib.so.19 => not found
    libblas.so.3 => /usr/lib/x86_64-linux-gnu/libblas.so.3 (0x00007f35f50b0000)
    liblapack.so.3 => /usr/lib/x86_64-linux-gnu/liblapack.so.3 (0x00007f35f47f1000)
    libjpeg.so.8 => /usr/lib/x86_64-linux-gnu/libjpeg.so.8 (0x00007f35f4589000)
    libresolv.so.2 => /lib/x86_64-linux-gnu/libresolv.so.2 (0x00007f35f436f000)
    libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f35f4150000)
    libstdc++.so.6 => /usr/lib/x86_64-linux-gnu/libstdc++.so.6 (0x00007f35f3dc7000)
    libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f35f3a29000)
    libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007f35f3811000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f35f3420000)
    /lib64/ld-linux-x86-64.so.2 (0x00007f35f5672000)
    libgfortran.so.4 => /usr/lib/x86_64-linux-gnu/libgfortran.so.4 (0x00007f35f3041000)
    libquadmath.so.0 => /usr/lib/x86_64-linux-gnu/libquadmath.so.0 (0x00007f35f2e01000)

I'm hosting my personal photo-blog (github) on a free VM in Oracle Cloud, and because I've set this machine up quite a while ago, it is stuck at Ubuntu 18.04 with only older libraries available by default. This was a reason I've tried to enable face recognition with a statically built app.

To separate fast-paced development with easy builds from complicated builds, I decided to implement facial recognition as a standalone microservice: https://github.com/vearutop/faces.

Let's see if we can get rid of dynamic dependencies and improve portability with static build.

Dlib already has everything needed for a build in isolation, but by default it would dynamically link with installed libs if they are available. Because of that, I'll try to build in a clean docker environment.

Let's create a playground Dockerfile.

./docker/Dockerfile:

FROM ubuntu:22.04 as builder

RUN apt-get update
RUN apt-get install -y build-essential cmake curl
RUN curl -sLO https://go.dev/dl/go1.21.6.linux-amd64.tar.gz && tar -C /usr/local -xzf go1.21.6.linux-amd64.tar.gz && rm -rf go1.21.6.linux-amd64.tar.gz
RUN mkdir /dlib && cd /dlib && curl -sLO http://dlib.net/files/dlib-19.24.tar.bz2 && tar xf dlib-19.24.tar.bz2
RUN cd /dlib/dlib-19.24 && mkdir build && cd build && cmake .. && cmake --build . --config Release && make install && rm -rf /dlib

docker build -f ./docker/Dockerfile -t builder .

Once the build is ready, we can get into a container with our app code mounted.

docker run --rm -v $PWD:/app -w /app -it builder /bin/bash

root@f08033dcccbc:/app# ls
LICENSE  Makefile  README.md  bin  dev_test.go  docker  faces.go  go.mod  go.sum  models  unit.coverprofile  vendor

I've downloaded all dependencies with go mod vendor to simplify operations in the container.

In order to build statically, we need to set CGO_LDFLAGS="-static" for the go build.

root@f08033dcccbc:/app# CGO_LDFLAGS="-static" /usr/local/go/bin/go build .
# github.com/Kagami/go-face
jpeg_mem_loader.cc:3:10: fatal error: jpeglib.h: No such file or directory
    3 | #include <jpeglib.h>
      |          ^~~~~~~~~~~
compilation terminated.

Build failed on a missing header file that was supposed to be installed with one of the dependencies. Let's see if we have that file somewhere in container.

root@f08033dcccbc:/app# find / -name '*jpeglib.h'
/usr/local/include/dlib/external/libjpeg/jpeglib.h

Header files are looked up in /usr/include/ by default. For a quick and dirty fix, we can copy the missing file(s) there.

root@f08033dcccbc:/app# cp /usr/local/include/dlib/external/libjpeg/*.h /usr/include/

Let's run the build again!

root@f08033dcccbc:/app# CGO_LDFLAGS="-static" /usr/local/go/bin/go build .
# github.com/vearutop/faces
/usr/local/go/pkg/tool/linux_amd64/link: running g++ failed: exit status 1
/usr/bin/ld: cannot find -lblas: No such file or directory
/usr/bin/ld: cannot find -lcblas: No such file or directory
/usr/bin/ld: cannot find -llapack: No such file or directory
/usr/bin/ld: cannot find -ljpeg: No such file or directory
collect2: error: ld returned 1 exit status

Bad luck, it failed with another error now. Linker complains that it cannot link against a few missing libs, but all of them should already be included in dlib build.

If we search our codebase (including vendor), we'll find this line in face.go:

// #cgo LDFLAGS: -ldlib -lblas -lcblas -llapack -ljpeg

This is a linker instruction with list of libs that's causing the problem now. Fortunately, with vendored deps it is super easy to change code of dependencies, so let's change that line to this:

// #cgo LDFLAGS: -ldlib

Let's run the build one more time.

root@f08033dcccbc:/app# CGO_LDFLAGS="-static" /usr/local/go/bin/go build .
# github.com/vearutop/faces
/usr/bin/ld: /tmp/go-link-3191459515/000010.o: in function `_cgo_9c8efe9babca_C2func_getaddrinfo':
/tmp/go-build/cgo-gcc-prolog:58: warning: Using 'getaddrinfo' in statically linked applications requires at runtime the shared libraries from the glibc version used for linking
root@f08033dcccbc:/app# ./faces -help
Usage of ./faces:
  -listen string
        listen address (default "localhost:8011")
root@f08033dcccbc:/app#

It complained about something, but worked!
Let's check the dependencies now.

root@f08033dcccbc:/app# ldd ./faces
        not a dynamic executable

This looks like a nice statically built binary! 😌

Let's check if it actually works. In the same container I can run the app in background with:

root@f08033dcccbc:/app# ./faces &
[1] 1739
root@f08033dcccbc:/app#

And then invoke request with curl:

root@f08033dcccbc:/app# curl -X 'POST' \
'http://localhost:8011/image' \
-H 'accept: application/json' \
-H 'Content-Type: multipart/form-data' \
-F 'image=@person.jpg;type=image/jpeg'

{"elapsedSec":0.258315,"found":1,"faces":[{"Rectangle":{"Min":{"X":352,"Y":185},"Max":{"X":567,"Y":400}},"Descriptor":[-0.16648848,-0.05050624,0.106586605,-0.0867105,-0.09123391,-0.097584575,-0.046739854,-0.103373915,0.074457884,-0.105268024,0.20660394,-0.13579035,-0.2745444,0.0005242062,-0.03232275,0.18681777,-0.13113116,-0.17754263,-0.052810747,-0.05957584,0.0062686643,-0.03621107,0.011501403,0.1487859,-0.06366991,-0.33826596,-0.06331841,-0.08673793,-0.010200936,-0.0629237,0.027267495,0.11619936,-0.2607339,-0.04982499,0.01518264,0.12889145,0.02307811,-0.118307345,0.1285096,-0.048686076,-0.24529652,-0.12607978,0.136835,0.26203102,0.162219,0.034145266,0.018228233,-0.0061597005,0.040899806,-0.295318,0.0031301053,0.06259319,0.0745079,0.049838964,0.00964687,-0.27123472,0.07631222,0.060989577,-0.12530015,0.03486493,0.035399184,-0.04188027,0.04090107,-0.051638283,0.36773872,0.10492739,-0.14495152,-0.087634355,0.21060707,-0.16210485,-0.00697436,0.04431132,-0.16566163,-0.12653385,-0.31701985,-0.06338993,0.31295794,0.03408507,-0.17158867,0.076981254,-0.09508267,0.073756054,0.02041351,0.14637248,-0.0001675617,0.10626993,-0.08162568,-0.01661037,0.23682739,-0.021808863,-0.006492801,0.22029987,-0.01065092,-0.044090617,0.09562777,0.039906204,-0.05015147,-0.061895538,-0.21429531,0.028714905,-0.07911338,-0.017555084,-0.02431442,0.106665134,-0.20538758,0.08050651,0.017503517,-0.0074621206,-0.057238452,0.036879964,-0.08754097,-0.09878489,0.111212455,-0.24645737,0.15643074,0.21560076,0.10718059,0.13916788,0.05442419,0.053753562,0.024602186,-0.011599961,-0.13366313,-0.02042818,0.062051836,-0.0836075,-0.010100439,0.07831607],"Shapes":[{"X":529,"Y":253},{"X":492,"Y":251},{"X":399,"Y":237},{"X":436,"Y":245},{"X":457,"Y":309}]}]}

To wrap up, let's add our findings in app codebase.

If we now try to build the app outside a container with dynamic linking, the build will fail because we've removed linker instructions in vendored code. To make it work for both cases we can guard behavior with build flags. Let's remove the // #cgo LDFLAGS: ... line from face.go and create two new files instead.

face_static.go:

//go:build static
package face

// #cgo LDFLAGS: -ldlib
import "C"

face_dynamic.go:

//go:build !static
package face

// #cgo LDFLAGS: -ldlib -lblas -lcblas -llapack -ljpeg
import "C"

Now we'll need to add a build tag in order to build statically, but the default build will use dynamic linking.

root@f08033dcccbc:/app# CGO_LDFLAGS="-static" /usr/local/go/bin/go build -tags static .

Let's update our Dockerfile with more instructions to perform the actual application build.

FROM ubuntu:22.04 as builder

RUN apt-get update
RUN apt-get install -y build-essential cmake curl
RUN curl -sLO https://go.dev/dl/go1.21.6.linux-amd64.tar.gz && tar -C /usr/local -xzf go1.21.6.linux-amd64.tar.gz && rm -rf go1.21.6.linux-amd64.tar.gz
RUN mkdir /dlib && cd /dlib && curl -sLO http://dlib.net/files/dlib-19.24.tar.bz2 && tar xf dlib-19.24.tar.bz2
RUN cd /dlib/dlib-19.24 && mkdir build && cd build && cmake .. && cmake --build . --config Release && make install && rm -rf /dlib

# Missing header file.
RUN cp /usr/local/include/dlib/external/libjpeg/*.h /usr/include/

# Building app.
WORKDIR /app
ADD . .
RUN CGO_LDFLAGS="-static" /usr/local/go/bin/go build -tags static .

# Exporting minimal docker image with pre-built binary.
FROM alpine
WORKDIR /root
CMD ["/bin/faces", "-listen", "0.0.0.0:80"]
COPY --from=builder /app/faces /bin/faces

After that we can run a clean build.

docker build -f ./docker/Dockerfile -t faces .

Now, if you need resulting binary to deploy it somewhere, you can copy it from docker image.

docker run -v $PWD:/opt/mount --rm faces cp /bin/faces /opt/mount/faces

As a result you'll have ./faces in your current directory.

Or you can start the service on http://localhost:8000 with docker.

docker run --rm -p 8000:80 faces

Streaming generated data as io.Reader at high speed in Go

Viacheslav Poturaev — Tue, 22 Aug 2023 00:42:06 +0000

When you want to benchmark a piece of code that processes io.Reader, it is common to use io.Pipe to stream generated data with an extra io.Writer.

Take a look at this trivial example benchmark.

func Benchmark_ioPipe(b *testing.B) {
    r, w := io.Pipe()
    i := 0

    go func() {
        for {
            i++

            if i == b.N {
                _ = w.Close()

                return
            }

            _, _ = w.Write([]byte("<this might be a dynamic piece of generated data>\n"))
        }
    }()

    b.ReportAllocs()

    // io.Copy acts as a dummy processor here, in real-world 
    // scenario you'd have an actual io.Reader consumer.
    if _, err := io.Copy(io.Discard, r); err != nil {
        b.Fatal(err.Error())
    }
}

cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
Benchmark_ioPipe-12      1655488           729.8 ns/op        64 B/op          1 allocs/op

Performance of such feed is not bad, but not very impressive either. Some speed is sacrificed to enable data safety under concurrency, both reads and writes can be called in parallel with synchronization happening in the pipe.

Let's try to improve performance for a particular case of generated feed exposed as io.Reader, that does not need external synchronization.

type pagesReader struct {
    // next returns contents of the next page, 
    // io.EOF error indicates last page.
    next func() ([]byte, error)

    // buf keeps the data to be read.
    buf []byte
}

func (r *pagesReader) Read(p []byte) (n int, err error) {
    // Fill the reader buffer with pages 
    // until it exceeds the incoming buffer 
    // or reaches the end of pages.
    for len(r.buf) < len(p) {
        page, err := r.next()
        r.buf = append(r.buf, page...)
        if err != nil {
            copy(p, r.buf)
            return len(r.buf), err
        }
    }

    // Put head of reader buffer in the incoming buffer.
    copy(p, r.buf)

    // Move remaining tail into the head of reader buffer.
    remaining := r.buf[len(p):]
    r.buf = r.buf[:len(remaining)]
    copy(r.buf, remaining)

    return len(p), nil
}

pagesReader implements io.Reader that feeds data from user-defined callback next func() ([]byte, error).

Now, let's update the previous benchmark to use pagesReader instead of io.Pipe.

func Benchmark_pagesReader(b *testing.B) {
    i := 0
    r := &pagesReader{
        next: func() ([]byte, error) {
            i++

            if i == b.N {
                return nil, io.EOF
            }

            return []byte("<this might be a dynamic piece of generated data>\n"), nil
        },
    }

    b.ReportAllocs()

    // io.Copy acts as a dummy processor here, in real-world
    // scenario you'd have an actual io.Reader consumer.
    if _, err := io.Copy(io.Discard, r); err != nil {
        b.Fatal(err.Error())
    }
}

cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
Benchmark_pagesReader-12        21766588            52.38 ns/op       64 B/op          1 allocs/op

The unsynchronized implementation is much faster (about 14x speed) and might be more suitable for benchmarks for lower impact on overall result.

When synchronization is needed, it can be managed with a mutex in the next function itself.

Using code coverage to debug large Go application

Viacheslav Poturaev — Tue, 15 Aug 2023 12:45:25 +0000

Code coverage is typically used as a code quality metric.

One can run

go test -coverpkg ./... -coverprofile test.cov ./...

and receive a test.cov file containing information on how often particular parts of code were triggered during execution.

This is a great tool to keep your tests relevant.

However, code coverage can also help you to debug large codebases!

Imagine a situation when a seemingly innocent change in code leads to broken tests. Getting to the root cause might be non-trivial if there is a lot of code involved in execution.

In smaller cases, you could walk through all the statements with a debugger and compare state and conditions, but when you have thousands of statements, this approach is not really feasible.

Code coverage can help you to narrow down the scope of debugging.

Here is the recipe. The prerequisite is that you have a test that passes in original code, and fails in new.

Collect coverage

Collect coverages of both failure and pass.

It is important to collect coverage across all packages to have a wholistic picture. You can use ./... or something like my-module/..., github.com/foo/my-module/... for -coverpkg.

Apply the change and run the test.

go test -cover -coverpkg ./... -coverprofile new.cover -run ^Test_Foo$ ./path/to/tested/package

Then revert the change and collect coverage again.

go test -cover -coverpkg ./... -coverprofile orig.cover -run ^Test_Foo$ ./path/to/tested/package

After that, you will end up having two files: orig.cover and new.cover.

They might be big, but hopefully not very different.

Coverage file may look like this.

mode: set
github.com/swaggest/jsonschema-go/camelcase.go:14.31,21.22 6 1
github.com/swaggest/jsonschema-go/camelcase.go:21.22,22.27 1 1
github.com/swaggest/jsonschema-go/camelcase.go:22.27,24.4 1 1
github.com/swaggest/jsonschema-go/camelcase.go:26.3,26.27 1 1
github.com/swaggest/jsonschema-go/camelcase.go:26.27,28.4 1 1
github.com/swaggest/jsonschema-go/camelcase.go:30.3,30.27 1 1
.....

The first line says which mode of coverage collection was used.

All the other lines describe a span of code (file:start_line.start_col,end_line.end_col) with a total number of statements in that span and a number of statements executed.

Create coverage diff

Coverage files are ordered alphabetically, so they are friendly to diff.

diff orig.cover new.cover > diff.cover

The resulting file may look somewhat similar to this.

305c305
< github.com/swaggest/jsonschema-go/helper.go:75.46,78.16 2 1
---
> github.com/swaggest/jsonschema-go/helper.go:75.46,78.16 2 0
307c307
< github.com/swaggest/jsonschema-go/helper.go:82.2,84.46 2 1
---
> github.com/swaggest/jsonschema-go/helper.go:82.2,84.46 2 0
309c309
< github.com/swaggest/jsonschema-go/helper.go:88.2,88.15 1 1

You can already spot that the lines here are mostly different in the number of executed statements. This is the clue for us that those places in code are the best candidates to have a deeper look with a debugger.

Let's make this diff more convenient to follow and check.

Coverage reporting

Lines starting with < represent the original code, lines starting with > are about the new code.

We can build filtered coverage reports from the diff.

For that, we need to restore the mode: set and remove "< " or "> " from the lines.

echo "mode: set" > orig_flt.cover && grep "< " diff.cover | sed 's/< //' >> orig_flt.cover

echo "mode: set" > new_flt.cover && grep "> " diff.cover | sed 's/> //' >> new_flt.cover

Now, there are two coverage files that only contain differences between two runs.

We can conveniently inspect them with standard go tool cover.

go tool cover -html=orig_flt.cover -o orig_flt.html
go tool cover -html=new_flt.cover -o new_flt.html

You can see which parts of code were executed differently, this can lead to an idea of what could be the root cause or at least can give a hint where debugger break point should be set.

I hope you've enjoyed reading this as much as I enjoyed digging into a huuuuge code base with this approach. :)

UPD: Check a newer relevant post from Russ Cox too https://research.swtch.com/diffcover.

Profile-guided optimization of a Go application

Viacheslav Poturaev — Sun, 19 Mar 2023 19:49:30 +0000

TL;DR Go 1.20 PGO was applied to an existing high-performance application and lead to 2% faster execution with 4.4% less CPU cycles and 5.3% less CPU instructions for extra 100KB size of compiled binary.

A recent release of Go (1.20) introduced a preview version of a new tool to optimize an application in response to performance counters of a CPU profile.

Profile-guided optimization can enable inlining for functions in hot paths, this is a trade-off between increased binary size and improved speed of execution.

CPU profile makes this trade-off informed and allows a relatively low binary size penalty for a noticeable perf improvement.

I have flatjsonl, an application that processes JSON lines and renders them as tables. Speed of processing is important, so any optimization is welcome, let's see how PGO can help.

CPU Profile

First, a relevant CPU profile is needed. There is already standard tooling for that, CPU profile is basically a collection of metrics and counters observed during application execution. For PGO purposes best results can be obtained using profiles of actual production workloads.

For a CLI app common practice is to define a flag to enable profile collection.

package main

import (
    "flag"
    "runtime/pprof"
...
func main()
    var cpuProfile    string
    flag.StringVar(&cpuProfile, "dbg-cpu-prof", "", "Write CPU profile to file.")
...
    flag.Parse()
...
    if cpuProfile != "" {
        f, err := os.Create(cpuProfile)
        if err != nil {
            log.Fatal(err)
        }

        if err = pprof.StartCPUProfile(f); err != nil {
            log.Fatal(err)
        }

        defer pprof.StopCPUProfile()
    }
...

If you're developing a web service, you can use net/http/pprof to expose profiling handler and collect data on a running instance.

I have a sample of work for flatjsonl, that is a production workload. If I run it multiple times it takes roughly the same time to process and produces same output, running such command is an idempotent operation.

flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst

So, to collect CPU profile I'll run it again with -dbg-cpu-prof flag.

flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst -dbg-cpu-prof default.pgo

After the action is complete I can find default.pgo file, name of the resulting profile file can be any, however, default.pgo is a special name supported by PGO mode auto.

PGO is implemented in a way that it can tolerate obsolete CPU profiles (e.g. built with an older version of an application), though more obsolete profile would lead to less efficient PGO.

Instrumented Build

Once CPU profile is collected, it can be used with go build

go build -pgo=auto

go build -pgo=/path/to/cpu.pprof

if profile is stored in other place than ./default.pgo.

In this case PGO instrumentation resulted in ~100KB extra size.

8527872 (8.2M) flatjsonl
8626176 (8.3M) flatjsonl-pgo

Performance Impact

flatjsonl is optimized for multiple cores, performance was measured on a machine with 32 cores running Linux.

Go has benchmarking tools in standard library, but in this case it is easier to use hyperfine to measure performance of a CLI app.

Hyperfine

hyperfine --warmup 3 'flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst'
Benchmark 1: flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst
  Time (mean ± σ):      7.836 s ±  0.147 s    [User: 69.622 s, System: 4.279 s]
  Range (min … max):    7.504 s …  8.043 s    10 runs

hyperfine --warmup 3 'flatjsonl-pgo -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst'
Benchmark 1: flatjsonl-pgo -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst
  Time (mean ± σ):      7.660 s ±  0.305 s    [User: 66.129 s, System: 3.783 s]
  Range (min … max):    7.180 s …  8.106 s    10 runs

In this case, binary with PGO enabled worked ~2.2% faster.

Perf Stat

Linux provides another handy tool to inspect performance of an application, perf stat can count number of CPU instructions and cycles during program execution.

perf stat -e task-clock,cycles,instructions,cache-references,cache-misses flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst

<program output omitted>

Performance counter stats for 'flatjsonl -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst':

         71,107.29 msec task-clock:u              #    9.081 CPUs utilized
   152,046,064,828      cycles:u                  #    2.138 GHz
   193,579,158,625      instructions:u            #    1.27  insn per cycle
     1,498,126,007      cache-references:u        #   21.069 M/sec
       374,577,209      cache-misses:u            #   25.003 % of all cache refs

       7.830534779 seconds time elapsed

      68.273271000 seconds user
       3.311031000 seconds sys

perf stat -e task-clock,cycles,instructions,cache-references,cache-misses flatjsonl-pgo -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst

<program output omitted>

Performance counter stats for 'flatjsonl-pgo -config ./cfg.json5 -csv ~/all.csv.gz -field-limit 50000 -max-lines 300000 -input ~/slow.log.zst':

         70,220.34 msec task-clock:u              #    9.427 CPUs utilized
   145,321,922,303      cycles:u                  #    2.070 GHz
   183,258,560,907      instructions:u            #    1.26  insn per cycle
     1,543,859,683      cache-references:u        #   21.986 M/sec
       386,600,109      cache-misses:u            #   25.041 % of all cache refs

       7.448585196 seconds time elapsed

      64.659898000 seconds user
       6.057555000 seconds sys

Binary with PGO instrumentation used ~4.4% fewer CPU cycles and ~5.3% less instructions.

Such performance improvements may seem small, but instrumentation effort is almost free.

Memory arenas in Go

Viacheslav Poturaev — Thu, 09 Mar 2023 09:18:53 +0000

Recently released go1.20 brought a new experimental package named arena (proposal).

The purpose of this package is to isolate multiple related allocations into a single area of memory, so that they can be freed all at once.

Expected effect is improved allocation performance and reduced garbage collector (GC) pressure.

Let's see it in action. As a toy problem, we can use binary-trees.

A program that idiomatically solves this problem has to put a lot of pressure on a memory management system to allocate many small objects, so it is a great candidate to assess new arenas.

Original source code:
binary-trees-ptr.go

package main

import (
   "flag"
   "fmt"
   "strconv"
   "sync"
)

type Tree struct {
   Left  *Tree
   Right *Tree
}

// Count the nodes in the given complete binary tree.
func (t *Tree) Count() int {
   // Only test the Left node (this binary tree is expected to be complete).
   if t.Left == nil {
      return 1
   }
   return 1 + t.Right.Count() + t.Left.Count()
}

// Create a complete binary tree of `depth` and return it as a pointer.
func NewTree(depth int) *Tree {
   if depth > 0 {
      return &Tree{Left: NewTree(depth - 1), Right: NewTree(depth - 1)}
   } else {
      return &Tree{}
   }
}

func Run(maxDepth int) {

   var wg sync.WaitGroup

   // Set minDepth to 4 and maxDepth to the maximum of maxDepth and minDepth +2.
   const minDepth = 4
   if maxDepth < minDepth+2 {
      maxDepth = minDepth + 2
   }

   // Create an indexed string buffer for outputing the result in order.
   outCurr := 0
   outSize := 3 + (maxDepth-minDepth)/2
   outBuff := make([]string, outSize)

   // Create binary tree of depth maxDepth+1, compute its Count and set the
   // first position of the outputBuffer with its statistics.
   wg.Add(1)
   go func() {
      tree := NewTree(maxDepth + 1)
      msg := fmt.Sprintf("stretch tree of depth %d\t check: %d",
         maxDepth+1,
         tree.Count())

      outBuff[0] = msg
      wg.Done()
   }()

   // Create a long-lived binary tree of depth maxDepth. Its statistics will be
   // handled later.
   var longLivedTree *Tree
   wg.Add(1)
   go func() {
      longLivedTree = NewTree(maxDepth)
      wg.Done()
   }()

   // Create a lot of binary trees, of depths ranging from minDepth to maxDepth,
   // compute and tally up all their Count and record the statistics.
   for depth := minDepth; depth <= maxDepth; depth += 2 {
      iterations := 1 << (maxDepth - depth + minDepth)
      outCurr++

      wg.Add(1)
      go func(depth, iterations, index int) {
         acc := 0
         for i := 0; i < iterations; i++ {
            // Create a binary tree of depth and accumulate total counter with its
            // node count.
            a := NewTree(depth)
            acc += a.Count()
         }
         msg := fmt.Sprintf("%d\t trees of depth %d\t check: %d",
            iterations,
            depth,
            acc)

         outBuff[index] = msg
         wg.Done()
      }(depth, iterations, outCurr)
   }

   wg.Wait()

   // Compute the checksum of the long-lived binary tree that we created
   // earlier and store its statistics.
   msg := fmt.Sprintf("long lived tree of depth %d\t check: %d",
      maxDepth,
      longLivedTree.Count())
   outBuff[outSize-1] = msg

   // Print the statistics for all of the various tree depths.
   for _, m := range outBuff {
      fmt.Println(m)
   }
}

func main() {
   n := 0
   flag.Parse()
   if flag.NArg() > 0 {
      n, _ = strconv.Atoi(flag.Arg(0))
   }

   Run(n)
}

If I compile and run this program, I can get a baseline performance metric.

time ./binary-trees-ptr 21

stretch tree of depth 22         check: 8388607
2097152  trees of depth 4        check: 65011712
524288   trees of depth 6        check: 66584576
131072   trees of depth 8        check: 66977792
32768    trees of depth 10       check: 67076096
8192     trees of depth 12       check: 67100672
2048     trees of depth 14       check: 67106816
512      trees of depth 16       check: 67108352
128      trees of depth 18       check: 67108736
32       trees of depth 20       check: 67108832
long lived tree of depth 21      check: 4194303

real    0m7.232s
user    1m9.929s
sys     0m0.959s

The actual program output is not so important, but the execution time is.

This result was obtained with a general purpose Macbook Pro (Intel) and in consecutive runs the numbers were slightly different. However, this post does not aim for scientific accuracy, the goal is to have rough understanding what to expect from arenas. Performance impact may vary depending on the code, so please run proper benchmarks on your actual cases.

Most allocations in the app are happening in

func NewTree(depth int) *Tree {
   if depth > 0 {
      return &Tree{Left: NewTree(depth - 1), Right: NewTree(depth - 1)}
   } else {
      return &Tree{}
   }
}

Enter `arena`

This new package is available in std lib with "arena" import.
The flow is

create arena instance with arena.NewArena(),
use it to allocate instances of any type with arena.New[T any](a *Arena) *T,
use it to allocate slices with arena.MakeSlice[T any](a *Arena, len, cap int) []T,
free arena instance once the data is no longer needed with (*Arena).Free().

Because this package is experimental, you'd need to explicitly enable it with GOEXPERIMENT=arenas env var and/or with equivalent build tag //go:build goexperiment.arenas during build.

Upgrade the app

Let's isolate tree constructor to allocate in an arena.

func NewTree(a *arena.Arena, depth int) *Tree {
    if depth > 0 {
        t := arena.New[Tree](a)
        t.Left = NewTree(a, depth-1)
        t.Right = NewTree(a, depth-1)
        return t
    } else {
        return arena.New[Tree](a)
    }
}

Now when we build a tree, we have control of where to put its data and when to free it.

.....
    // Create binary tree of depth maxDepth+1, compute its Count and set the
    // first position of the outputBuffer with its statistics.
    wg.Add(1)
    go func() {
        a := arena.NewArena()
        tree := NewTree(a, maxDepth+1)
        msg := fmt.Sprintf("stretch tree of depth %d\t check: %d",
            maxDepth+1,
            tree.Count())

        outBuff[0] = msg
        a.Free()
        wg.Done()
    }()
.....

Upgraded app:

binary-trees-ptr-arena.go

//go:build goexperiment.arenas

package main

import (
    "arena"
    "flag"
    "fmt"
    "strconv"
    "sync"
)

type Tree struct {
    Left  *Tree
    Right *Tree
}

// Count the nodes in the given complete binary tree.
func (t *Tree) Count() int {
    // Only test the Left node (this binary tree is expected to be complete).
    if t.Left == nil {
        return 1
    }
    return 1 + t.Right.Count() + t.Left.Count()
}

// Create a complete binary tree of `depth` and return it as a pointer.
func NewTree(a *arena.Arena, depth int) *Tree {
    if depth > 0 {
        t := arena.New[Tree](a)
        t.Left = NewTree(a, depth-1)
        t.Right = NewTree(a, depth-1)
        return t
    } else {
        return arena.New[Tree](a)
    }
}

func Run(maxDepth int) {

    var wg sync.WaitGroup

    // Set minDepth to 4 and maxDepth to the maximum of maxDepth and minDepth +2.
    const minDepth = 4
    if maxDepth < minDepth+2 {
        maxDepth = minDepth + 2
    }

    // Create an indexed string buffer for outputing the result in order.
    outCurr := 0
    outSize := 3 + (maxDepth-minDepth)/2
    outBuff := make([]string, outSize)

    // Create binary tree of depth maxDepth+1, compute its Count and set the
    // first position of the outputBuffer with its statistics.
    wg.Add(1)
    go func() {
        a := arena.NewArena()
        tree := NewTree(a, maxDepth+1)
        msg := fmt.Sprintf("stretch tree of depth %d\t check: %d",
            maxDepth+1,
            tree.Count())

        outBuff[0] = msg
        a.Free()
        wg.Done()
    }()

    // Create a long-lived binary tree of depth maxDepth. Its statistics will be
    // handled later.
    var longLivedTree *Tree
    la := arena.NewArena()
    wg.Add(1)
    go func() {
        longLivedTree = NewTree(la, maxDepth)
        wg.Done()
    }()

    // Create a lot of binary trees, of depths ranging from minDepth to maxDepth,
    // compute and tally up all their Count and record the statistics.
    for depth := minDepth; depth <= maxDepth; depth += 2 {
        iterations := 1 << (maxDepth - depth + minDepth)
        outCurr++

        wg.Add(1)
        go func(depth, iterations, index int) {
            acc := 0
            for i := 0; i < iterations; i++ {
                // Create a binary tree of depth and accumulate total counter with its
                // node count.
                ar := arena.NewArena()
                a := NewTree(ar, depth)
                acc += a.Count()
                ar.Free()
            }
            msg := fmt.Sprintf("%d\t trees of depth %d\t check: %d",
                iterations,
                depth,
                acc)

            outBuff[index] = msg
            wg.Done()
        }(depth, iterations, outCurr)
    }

    wg.Wait()

    // Compute the checksum of the long-lived binary tree that we created
    // earlier and store its statistics.
    msg := fmt.Sprintf("long lived tree of depth %d\t check: %d",
        maxDepth,
        longLivedTree.Count())
    outBuff[outSize-1] = msg
    la.Free()

    // Print the statistics for all of the various tree depths.
    for _, m := range outBuff {
        fmt.Println(m)
    }
}

func main() {
    n := 0
    flag.Parse()
    if flag.NArg() > 0 {
        n, _ = strconv.Atoi(flag.Arg(0))
    }

    Run(n)
}

Now is there any performance difference?

go build -tags goexperiment.arenas ./binary-trees-ptr-arena.go
time ./binary-trees-ptr-arena 21

stretch tree of depth 22         check: 8388607
2097152  trees of depth 4        check: 65011712
524288   trees of depth 6        check: 66584576
131072   trees of depth 8        check: 66977792
32768    trees of depth 10       check: 67076096
8192     trees of depth 12       check: 67100672
2048     trees of depth 14       check: 67106816
512      trees of depth 16       check: 67108352
128      trees of depth 18       check: 67108736
32       trees of depth 20       check: 67108832
long lived tree of depth 21      check: 4194303

real    0m5.777s
user    0m38.207s
sys     0m4.537s

Time difference is around 20% which is very impressive given such a small change to original program.

Keep in mind that a single arena can not be used concurrently (at least as of current implementation), but you can create multiple arenas for multiple goroutines.

Efficient code review

Viacheslav Poturaev — Fri, 14 Oct 2022 12:15:52 +0000

Code review can be lengthy and stressful, especially if change is complex.

If the change in question is very important and may have severe consequences, it is important to weigh diverse input and to arrive at an agreement or a reasonable compromise. Addressing valid concerns can reduce the risks of introducing a change.

Sometimes code review turns into an arena with clashes of strong opinions, this is not always necessary.

Code review takes resources that could have been spent in development. What does it bring in return?

Meaningfulness: reviewer can check that change makes sense from both problem and solution standpoints,
Correctness: reviewer can check that code change is sufficiently tested and does not have obvious logical flaws, typos/misspells, obsolete documentation,
Safety: reviewer can flag malicious, obscure or unreliable code,
Suitability: reviewer can check if the change meets performance expectations, reasonably utilizes available resources, and does not conflict with already existing code.
Consistency: reviewer can flag code that violates project conventions and/or common best practices,
Knowledge: reviewer and contributor can learn from each other by asking questions about particular decisions or by suggesting alternatives.

All the checks above are usually the best effort to the best knowledge of a reviewer, because doing a thorough and comprehensive assessment may be prohibitively expensive.

Scope Of a Change

Smaller changes are easier to manage. Small atomically correct changes are typically less risky. Small changes are easier to review and comprehend. Small changes are not always feasible to deliver (especially in code with tight coupling between the components), but they are something to strive for.

The pull request (change set) should have a primary goal clearly articulated in description. If code changes are directly relevant to the primary goal, that often allows reaching a minimal acceptable size of changes.

It might be tempting to put more changes in, to follow boy scout rule. But this bears risks of unbounded growth which may delay the primary goal delivery or even make the whole change set too big for a confident review. If an improvement idea arises during code review and if it does not directly contribute to the primary goal, it is worth considering delivering such improvement as a separate change.

Suggestions And Change Requests

Apart from clarification questions, code review can end with approval, suggestions, and change requests.

Change requests are blocking pull requests from being merged.
A change request should indicate a reason why original changes are not ready to be merged.

Change requests should be used to address insufficient meaningfulness, correctness, safety, suitability, and consistency (core properties).

If those properties are not violated, suggestions are preferred.

Suggestions, as opposed to change requests, do not block pull requests from being merged. They invite pull request authors to consider alternative solutions or additional changes that may be beneficial from reviewer perspective.

Suggestions can convey opinions on naming, layout, design patterns and other things that can not be backed by existing team conventions. Suggestions help to bring different perspectives in a friendly way and are often accepted by pull request authors. However, pull request authors have a right to politely decline a suggestion if they think it does not bring enough value for the risks (growth of scope, unclear impact on core properties).

Declined suggestions can still be delivered in a separate pull request to avoid scope creep, and they can pass through a separate code review.

Both suggestions and change requests can vary in how helpful they are. Helpful messages may contain actual changes that can be applied to the code in question.

Attitude

Miscommunications and misunderstandings can happen often. They can happen even more often in a diverse team, where people have their own biases and cultural background.

Miscommunication is harmful, from being just counter-productive time spending to a more severe issue when feelings are hurt.

It is very important to have positive assumptions. If a person is having negative preliminary bias or negative assumptions, such bias can color messages with neutral original intent into offensive ones, and can even lead to painful escalations.

While we're all people with emotions, pull request is a technical ground, sticking to technical language and technical argumentation together with explicit articulation can help to reduce miscommunications. If you feel offended by a message, take time to calm down and re-read the context with an effort to discover positive/neutral intent. There is a high chance that this was the original intent conveyed by the author.

Code review is a collaboration tool, we're doing it to be more successful as a team. The best outcome of a review is a quick and confident approval without any suggestions, such cases usually indicate a high level of harmony in a team.

Code review is not the best place to exercise one's own importance by nitpicking or asking for cosmetic/out-of-scope changes. If the suggestion feels important, but it meets justified resistance from a pull request owner and/or other reviewers, it might be a good idea to submit such a suggestion as a separate pull request.

Try to avoid making suggestions/change requests based solely on opinion. Opinions can vary from one person to another, and they can easily be a point of locked disagreement. The opinion of one person is not necessarily more significant than the opinion of another person, so there is a fundamental issue that may need the involvement of an authorized arbiter.

Technical argumentation with pros and cons (as opposed to just opinion) can lead to a balanced compromise or consensus.

Rules And Principles

All parties are egoless and committed to reach ideal handling
All parties take review process as an opportunity to learn
All parties are trying to communicate in a timely manner to avoid blocking each other
Review process does not take longer time than necessary
Contributor articulates the problem to be solved, comprehensible by reviewer
If the problem is a bug, contributor creates a test to reproduce the bug with CI before pushing a fix
Contributor makes changes that are directly relevant to the problem described in PR
Contributor avoids unnecessary changes
Contributor formats changes in a way that is consistent with existing code
Contributor applies boy scout rule when that does not violate above points
Contributor creates additional tests to cover new behavior
Contributor updates the tests to match changed behavior
Contributor makes sure the problem is solved (best effort)
Contributor is ready to provide justification for every change that was made
Reviewer comprehends PR description and the problem
If reviewer has a doubt or lack of understanding, they request a clarification
If clarification is requested, contributor reasonably elaborates the topic
Reviewer checks that problem of PR is worth solving
Reviewer checks changes in tests to confirm that the goal of PR is achieved
Reviewer checks changes in tests to confirm there are no unnecessary changes in behavior
Reviewer checks that changes do not introduce a security/performance issue (best effort)
Reviewer checks that changes do not have logical conflict with existing code (best effort)
Reviewer makes helpful change requests if necessary
Reviewer is ready to provide justification for change request
Helpful change request is suggestive, precise, and relevant to the problem of PR
Reviewer avoids unhelpful change requests
Unhelpful change request is broad, opinionated, or not relevant to the problem of PR
Contributor can challenge any change request
If justification of change request is shown to be weak, change request can be discarded
If helpfulness of a change request is questionable, reviewer can elaborate it to clearly helpful, or it can be discarded
Reviewer can challenge any change of PR
If justification of change is shown to be weak, contributor has to revert the change
If there are helpful change requests that could not be discarded, contributor has to address them with PR changes

Using Nginx as a proxy to multiple Unix sockets

Viacheslav Poturaev — Mon, 08 Aug 2022 08:59:00 +0000

TL;DR Listening port may be a contended resource on a busy shared machine, unix sockets are virtually unlimited. Nginx can expose them with a single port and prefixed URLs.

In some situations you may want to run many (instances of) applications on a single machine. Each instance may need to provide internal information (e.g. Prometheus /metrics, profiling/debug handlers) over restricted HTTP.

When number of instances grows it becomes a burden to provision listening ports without conflicts. In contrast, using Unix sockets allows for more transparency (readable filenames) and scalability (easy to come up with unique name).

Here is a small demo program written in Go that would serve trivial HTTP service with Unix socket.

package main

import (
    "context"
    "flag"
    "io/fs"
    "log"
    "net"
    "net/http"
    "os"
    "os/signal"
)

func main() {
    var socketPath string

    flag.StringVar(&socketPath, "socket", "./soc1", "Path to unix socket.")
    flag.Parse()

    if socketPath == "" {
        flag.Usage()
        return
    }

    listener, err := net.Listen("unix", socketPath)
    if err != nil {
        log.Println(err.Error())
        return
    }

    // By default, unix socket would only be available to same user.
    // If we want access it from Nginx, we need to loosen permissions.
    err = os.Chmod(socketPath, fs.ModePerm)
    if err != nil {
        log.Println(err)
        return
    }

    httpServer := http.Server{
        Handler: http.HandlerFunc(func(writer http.ResponseWriter, request *http.Request) {
            log.Println(request.URL.String())
            if _, err := writer.Write([]byte(request.URL.String())); err != nil {
                log.Println(err.Error())
            }
        }),
    }

    // Setting up graceful shutdown to clean up Unix socket.
    go func() {
        sigint := make(chan os.Signal, 1)
        signal.Notify(sigint, os.Interrupt)
        <-sigint
        if err := httpServer.Shutdown(context.Background()); err != nil {
            log.Printf("HTTP Server Shutdown Error: %v", err)
        }
    }()

    log.Printf("Service is listening on socket file %s", socketPath)
    err = httpServer.Serve(listener)
    if err != nil {
        log.Println(err.Error())
        return
    }
}

Now let's run a couple of instances in separate shells.

./soc -socket /home/ubuntu/soc1

./soc -socket /home/ubuntu/soc2

Here is a minimal Nginx config to serve those instances with URL prefixes. It would receive http://my-host/soc1/foo/bar, strip path prefix /soc1 and pass /foo/bar to soc1.

server {
    listen 80 default;

    location /soc1/ {
        proxy_pass http://soc1/;
    }
    location /soc2/ {
        proxy_pass http://soc2/;
    }
}

upstream soc1 {
    server unix:/home/ubuntu/soc1;
}

upstream soc2 {
    server unix:/home/ubuntu/soc2;
}

Every Unix socket is defined as upstream and has /location statement in server.

It is also possible to use Unix sockets directly in /location, like in

    location /soc1/ {
        proxy_pass http://unix:/home/ubuntu/soc1;
    }

however it has an unwanted limitation that you can not add trailing / to proxy_pass. And this means that URL will be passed as is, e.g. soc1 will receive /soc1/foo instead of /foo.

To avoid such limitation we can use named upstream and add trailing / to proxy_pass.

    location /soc1/ {
        proxy_pass http://soc1/; # Mind trailing "/".
    }

Implementing robust in-memory cache with Go

Viacheslav Poturaev — Thu, 12 May 2022 00:55:35 +0000

TL;DR In-memory caching is a great way to improve performance and resiliency of an application at cost of memory and delayed data consistency. You need to take care of concurrent updates, error caching, failover handling, background updates, expiration jitter and cache warmup with transfer.

The Story

Caching is one of the most efficient techniques to improve performance, because the fastest way to get rid of a task is skipping it. Unfortunately caching is not a silver bullet, in some cases you can not afford reusing result of a task due to transactionality/consistency constraints. Cache invalidation is notoriously one of two hard things in Computer Science.

It is best when domain operates on immutable data and so cache invalidation is not necessary. In such case cache is usually a net benefit. However, if there are requirements to keep mutable data in sync, cache invalidation is necessary.
The simplest strategy is to invalidate cache based on time to live (TTL). Even if seems like a bad fit compared to event-based invalidation, consider simplicity and portability. Events do not guarantee timely delivery, in worst case scenarios (for example if event broker is temporary down or overloaded) events could be even less precise than TTL.

Short TTL is often a good compromise between performance and consistency. It would reduce the load under heavy traffic acting as a barrier to the data source. For the low traffic impact would be negligible.

Demo Application

Let's start with a simple demo application. It will receive URL with query parameters and respond with a JSON object determined by those parameters. Unique results will be stored in database to make things realistically slow.

We're going to put some load on the application with a custom plt.

Custom plt has additional parameters:

cardinality - number of unique URLs to be generated, this affects cache hit rate,
group - number of requests with similar URL being sent at once, this imitates concurrent access to the same key.



go run ./cmd/cplt --cardinality 10000 --group 100 --live-ui --duration 10h --rate-limit 5000 curl --concurrency 200 -X 'GET'   'http://127.0.0.1:8008/hello?name=World&locale=ru-RU'   -H 'accept: application/json'

Such a command will start a client that will send 10000 different URLs in the loop, trying keep rate of 5000 requests per second by using up to 200 concurrent requests. Every URL would be sent in a batch of 100 requests to imitate concurrency on a single resource.

It will show live performance statistics and overall results.

Demo app has three modes of operation controlled by CACHE environment variable:

none - no caching, all requests are served with involvement of the database,
naive - naive caching with a simple map and TTL of 3 minutes,
advanced - caching using github.com/bool64/cache library that implements a number of features to improve performance and resiliency, TTL is also 3 minutes.

Application is available at github.com/vearutop/cache-story.
If you would like to experiment yourself with it, you can start it with make start-deps run.
It depends on docker-compose to spin up database, prometheus, grafana (http://localhost:3001) and jaeger (http://localhost:16686/). You can stop dependencies with make stop-deps later.

On my machine I was able to achieve ~500 RPS with no cache. After ~130 concurrent requests DB starts choking with Too many connections. Such result is not great, not terrible, but looks like an improvement opportunity.
Let's see what we can achieve with help of caching.

With advanced cache same laptop was able to show these results (roughly 60x throughput with lower latency).



go run ./cmd/cplt --cardinality 10000 --group 100 --live-ui --duration 10h curl --concurrency 100 -X 'GET'   'http://127.0.0.1:8008/hello?name=World&locale=ru-RU'   -H 'accept: application/json'



Requests per second: 25064.03
Successful requests: 15692019
Time spent: 10m26.078s

Request latency percentiles:
99%: 28.22ms
95%: 13.87ms
90%: 9.77ms
50%: 2.29ms

Bytes VS Structures

Which one is better?

That depends on the use case, byte cache (or storing data as []byte) have some advantages:

it grants immutability, because you'll need to decode a new value every time you need it,
it generally takes less memory, because of less fragmentation,
it is more friendly to garbage collector, because there is nothing to traverse through,
it can be easily sent over the wire, because it is exactly what wire expects,
allows precise memory limit, bytes are so easy to count.

Main disadvantage is the cost of encoding and decoding. In hot loops it can become prohibitively expensive.

Advantages of structures:

no need to encode/decode a value every time you need it,
better expressiveness as you can potentially cache things that can not be serialized,

Disadvantages of structure cache:

mutability, because you reuse same value multiple times it is quite easy to change it without intention,
memory usage, structures take relatively sparse areas of memory,
garbage collector pressure, if you have a large set of long-living structures, GC may spend significant time traversing them and proving they are still in use,
nearly impossible to impose a total memory limit on a cache instance, dynamically-sized items are stored on the heap together with everything else.

In this article we will use structure cache.

Naive Cache

The simplest in-memory cache is a map guarded by a mutex.
When you need a value for a key, you first check if it's in the cache and not expired.
If it's not, you build it from the data source and put it in the cache.
Then you return the value to the caller.

This logic is simple, but it has some drawbacks that may lead to critical issues.

Concurrent Updates

When multiple callers simultaneously miss the same key, they will all try to build the value. This can lead to a deadlock or to resource exhaustion with cache stampede failure.

Additionally, there will be extra latency for all the callers that would try to build the value.
If some of those builds fail, parent callers will fail even though there might be a valid value in the cache.

The issue can be simulated by using low cardinality with high grouping, so that many similar requests are sent at once.



go run ./cmd/cplt --cardinality 100 --group 1000 --live-ui --duration 10h --rate-limit 5000 curl --concurrency 150 -X 'GET'   'http://127.0.0.1:8008/hello?name=World&locale=ru-RU'   -H 'accept: application/json'

This chart shows application started with naive cache and then, on the blue marker it was restarted with advanced cache. As you can see key locking can have a significant impact on performance (mind Incoming Request Latency) and resource usage (mind DB Operation Rate).

The solution could be to block parallel builds, so that only one build is in progress at a time. But this would suffer from contention if there are many concurrent callers asking for a variety of keys.

A better solution is to lock the builds per key, so that one of the callers acquires the lock and owns the build, while all the others wait for the value.

Background Updates

When cached entry expires it needs a new value, building new value can be slow. If we do it synchronously, we'll slow down tail latency (99+ percentile). For cache entries that are in high demand it is feasible to start the build in advance, even before the value is expired. It can also work if we can afford some level of staleness for the expired value.

In such case we can immediately serve stale/soon-to-be-expired value and start update in background. One caveat here is that if build depends on parent context, the context may be cancelled right after we served stale value (for example when parent HTTP request was fulfilled). If we use such context to access database, we'll get a context canceled error.
Solution for this problem is to "detach" the context from the parent context and ignore parent cancellation.
Update: Go 1.21 added WithoutCancel to the context package.

Another strategy might be to proactively rebuild cached entries that are soon to be expired, without a parent request, but this may lead to resource exhaustion due to keeping obsolete cache entries that are of no interest to anybody.

Expiration Sync

Imagine situation that we start a new instance with TTL cache enabled, cache is empty and almost every request leads to cache miss and value creation. This will spike the load on the data source and store cached entries with very close expiration time. Once TTL have passed, the majority of cached entries will expire almost simultaneously, this will lead to a new load spike. Updated values will have close expiration time again and situation will repeat.

This is a common problem for hot cache entries.

Eventually cache entries will come out of sync, but this may take a while.

Solution to this problem is to break the sync by adding jitter to the expiration time.
If expiration jitter is 10% (0.1) it means TTL will vary from 0.95 * TTL to 1.05 * TTL. Even such a small jitter will already help to reduce expiration synchronization.

Here is an example, we're pushing load with high cardinality and high concurrency on the service. It will require many entries to be available in short period of time, enough to form an expiration spike.



go run ./cmd/cplt --cardinality 10000 --group 1 --live-ui --duration 10h --rate-limit 5000 curl --concurrency 200 -X 'GET' 'http://127.0.0.1:8008/hello?name=World&locale=ru-RU' -H 'accept: application/json'

The chart starts with naive cache that does not do anything to avoid the sync, second marker indicates service restart with advanced cache that has 10% jitter added to the expiration time. Spikes are wider and shorter and fall faster, overall service stability is better.

Errors Caching

When value build fails the easiest thing to do is just return that error to the caller and forget about it.
This can lead to severe issues.

For example, your service works well and handles 10K RPS with help of cache, but suddenly cache builds start to fail (be it because of temporary database overload, network issue or maybe even logical error like failing validation).
At this point all 10K RPS (instead of usual 100 RPS) will hit data source directly because there will be no cache to serve.

Minor temporary outage would escalate exponentially.

For high load systems it is very important to cache failures with short TTL to avoid cascading failures.

Having a situation when high performance system can drop out of its pattern and face drastic degradation is sometimes called a "Performance Cliff".

Failover Mode

Sometimes serving obsolete value is better than returning error. Especially if obsolete value expired recently and there is still high chance that it is equal to an up-to-date value.

Failover mode helps to improve resiliency at cost of accuracy, which is often a fair tradeoff in distributed systems.

Cache Transfer

Cache works best when it has relevant data.
When a new instance of application is started, cache is empty.
Populating helpful data takes time, during this time cache efficiency may degrade significantly.

There are a few ways to work around the issue of "cold" cache.

You can warm up the cache by iterating over the data that is assumed to be useful. For example, you can fetch recent contents of a database table and store them in cache. This approach is complex and not always effective.
You need to decide what data to use and rebuild cache entries with a piece of bespoke code. This may put excessive load on the database (or other sources of data).

You can also avoid this issue by using a shared instance of cache, like redis or memcached. It has another issue, reading data over the network is much slower, than from local memory. Also, network bandwidth may become a scalability bottleneck. Wired data needs to be deserialized which adds on latency and resource usage.

The simple solution to this problem is to transfer cache from active instance to the newly started. Cached data of active instance naturally has high relevance, because it was populated in response to actual user requests. Transferring cache does not need to rebuild data and so it won't abuse data sources.

Usually production systems have multiple instances of application running in parallel. During deployment, these instances are restarted sequentially, so there is always an instance that is active and has high quality cache.

Go has a built-in binary serialization format encoding/gob. It helps to transfer data over the wire with minimal effort. The limitation is that it is based on reflection and needs data to have exported fields.

Another caveat with cache transfer is that different versions of application may have different data structures that are not necessarily compatible. To mitigate this issue, you can fingerprint cached structures (using reflection) and abort transfer in case of discrepancy.

Here is a sample implementation.



// RecursiveTypeHash hashes type of value recursively to ensure structural match.
func recursiveTypeHash(t reflect.Type, h hash.Hash64, met map[reflect.Type]bool) {
    for {
        if t.Kind() != reflect.Ptr {
            break
        }

        t = t.Elem()
    }

    if met[t] {
        return
    }

    met[t] = true

    switch t.Kind() {
    case reflect.Struct:
        for i := 0; i < t.NumField(); i++ {
            f := t.Field(i)

            // Skip unexported field.
            if f.Name != "" && (f.Name[0:1] == strings.ToLower(f.Name[0:1])) {
                continue
            }

            if !f.Anonymous {
                _, _ = h.Write([]byte(f.Name))
            }

            recursiveTypeHash(f.Type, h, met)
        }

    case reflect.Slice, reflect.Array:
        recursiveTypeHash(t.Elem(), h, met)
    case reflect.Map:
        recursiveTypeHash(t.Key(), h, met)
        recursiveTypeHash(t.Elem(), h, met)
    default:
        _, _ = h.Write([]byte(t.String()))
    }
}

Transfer can be done with HTTP or any other suitable protocol. In this example, we will use HTTP, served at /debug/transfer-cache. Please be aware that cache may contain sensitive information and should not have exposure to public.

For sake of this example, we can perform transfer with help of a separate instance of an application serving on a different port.



CACHE_TRANSFER_URL=http://127.0.0.1:8008/debug/transfer-cache HTTP_LISTEN_ADDR=127.0.0.1:8009 go run main.go



2022-05-09T02:33:42.871+0200    INFO    cache/http.go:282       cache restored  {"processed": 10000, "elapsed": "12.963942ms", "speed": "39.564084 MB/s", "bytes": 537846}
2022-05-09T02:33:42.874+0200    INFO    brick/http.go:66        starting server, Swagger UI at http://127.0.0.1:8009/docs
2022-05-09T02:34:01.162+0200    INFO    cache/http.go:175       cache dump finished     {"processed": 10000, "elapsed": "12.654621ms", "bytes": 537846, "speed": "40.530944 MB/s", "name": "greetings", "trace.id": "31aeeb8e9e622b3cd3e1aa29fa3334af", "transaction.id": "a0e8d90542325ab4"}

This chart shows application restarts at blue markers, last two are made with cache transfer. You can see that performance remains unaffected, while when there is no cache transfer there is a significant warmup penalty.

A less obvious benefit is that cache can also be transferred to a local instance on developer machine, this can help to reproduce and debug production issues much easier.

Lock Contention And Low-level Performance

Essentially every cache implementation acts as a map of values by keys with concurrent (mostly read) access.

Low-level performance concerns can be considered irrelevant in many cases. For example, if you use in-memory cache to power your HTTP API, even the simplest solution with map and mutex will likely be sufficient. That is because IO operations that are performed to serve HTTP are way slower than memory operations (even with synchronization penalties). This is important to keep in mind to avoid premature optimizations and unjustified complexity.

If the application that relies on in-memory cache is mostly CPU-bound, lock contention may become significant in overall performance.

Problem with lock contention is that concurrent reads and writes have to be synchronized in order to avoid data conflicts. In case of single mutex such synchronization would impose a limitation of only one operation at a time. This means modern CPUs with multiple cores would not be able to use all the capacity.

For mostly-read workloads standard sync.Map offers great performance, however, it degrades with more writes. There is a another custom implementation that outperforms sync.Map thanks to Cache-Line Hash Table (CLHT) data structure: github.com/puzpuzpuz/xsync.Map.

Another popular approach to reduce lock contention is map sharding (fastcache, bigcache, bool64/cache), when values are deterministically distributed in separate buckets based on keys. It has a good balance of simplicity and performance.

Memory Management

Memory is a limited resource, so cache should not grow indefinitely.

Expired items should eventually be removed from the cache.
This can be done synchronously or in background. Background janitor is a good idea, because it will not block the application.
Also, background janitor can be configured to remove items with a delay, so that expired value is still available as a failover backup.

Removing expired items might be not enough to keep memory usage under control.
There are different strategies to decide which items to evict.
When deciding on a strategy you should find a balance between CPU/memory usage and hit/miss ratio. Ultimately, goal of eviction is to optimize hit/miss ratio while remaining in acceptable performance budget, so this is the metric you need to look at when evaluating eviction strategies.

Here are some popular criteria to pick an item:

least-frequently used (LFU), relatively expensive as it needs to maintain counters that should be updated on every access,
least-recently used (LRU), relatively expensive as it needs to update item timestamps or reorder the list of keys on every access,
first in first out (FIFO), relatively cheap as it can use values that are populated once item cache is created,
random item, most performant, does not need any kinds of sorting, the least accurate.

I would suggest to evaluate FIFO and random eviction first, and only invest in LRU/LFU if it has proven significant impact on hit/miss ratio.

Now that you have a good idea about how to pick an eviction strategy, next question is "when and how many items should be evicted?".

This is a trivial question for []byte cache, most of the implementations provide you precise control over how much memory to use.

The question is tricky for structure cache. There is no feasible and reliable way to determine impact of a particular structure on the heap memory usage during application execution, this information may be available to GC, but not to the application itself.

Two less precise, but still useful, metrics are:

total count of items in the cache,
total memory usage of the whole application.

Both metrics can be easily obtained during application execution, and then lead to eviction.
Because these metrics are not linearly proportional to cache memory usage, they can not be used to calculate the exact list of items to evict.
An appropriate response would be to evict a configurable fraction of the items (for example 10% of the items), once eviction is triggered.

Heap impact of cached data largely depends on mapping implementation.
As you can see from the benchmark below, map[string]struct{...} may have 4x memory consumption compared to efficient binary serialization (uncompressed).

Baseline Benchmark

Here is a baseline benchmark for storing 1M small structures (struct { int, bool, string }) and accessing them with 10% and 0.1% writes.
Byte caches are instrumented with binary de/encoder of structure.



goos: darwin
goarch: amd64
cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz



name             MB/inuse   time/op (10%) time/op (0.1%)      
sync.Map         192 ± 0%   142ns ± 4%    29.8ns ±10%   // Great for read-heavy workloads.
shardedMap       196 ± 0%   53.3ns ± 3%   28.4ns ±11%   
mutexMap         182 ± 0%   226ns ± 3%    207ns ± 1%    
rwMutexMap       182 ± 0%   233ns ± 2%    67.8ns ± 2%   // RWMutex perf degrades with more writes.
shardedMapOf     181 ± 0%   50.3ns ± 3%   27.3ns ±13%   
ristretto        346 ± 0%   167ns ± 8%    54.1ns ± 4%   // Failed to keep full working set, ~7-15% of the items are evicted.
xsync.Map        380 ± 0%   31.4ns ± 9%   22.0ns ±14%   // Fastest, but a bit hungry for memory.
patrickmn        184 ± 0%   373ns ± 1%    72.6ns ± 5%   
bigcache         340 ± 0%   75.8ns ± 8%   72.9ns ± 3%   // Byte cache.
freecache        333 ± 0%   98.1ns ± 0%   77.8ns ± 2%   // Byte cache.
fastcache       44.9 ± 0%   60.6ns ± 8%   64.1ns ± 5%   // A true champion for memory usage, while having decent performance.

If serialization is not a problem fastcache is the best for its outstanding memory usage.

For CPU-bound applications xsync.Map offers the best performance.

Also, byte cache does not necessarily mean efficient memory usage, as shown by bigcache (ha!) and freecache.

Developer Friendliness

Programs that we write do not always behave like we want them to. Complexity leads to unexpected issues, that are hard to debug.
Unfortunately, caching makes this problem even worse. That's why it is especially important to make caching developer-friendly.

Cache may become poisoned for a variety of reasons, it should be possible to clean it up quickly and safely.
For that, consider having a special control to invalidate all cached items.
Under heavy load invalidation does not necessarily mean "deletion", if all cache is deleted at once data sources will receive excessive load and may fail.
A more gentle invalidation is "expiration" of all items with background update, while serving stale data.

Cache entry can become outdated and would mislead if somebody is investigating particular data source issues. It is convenient to disable cache for a particular request, so that cache inaccuracy can be ruled out. This may be implemented with a special header and then context instrumentation in middleware. Please be aware that such controls should not be available for public users as they can be used as for DOS attack.

Fine control over logs and metrics of cache operations/state is also important.

And finally, now that Go introduced type parameters (generics), it is possible to leverage type-safe APIs for cache interfaces and offset more burden on compiler.

GitHub Actions with unstable Go

Viacheslav Poturaev — Sat, 26 Feb 2022 08:34:47 +0000

Upcoming Go 1.18 release brings very interesting new features (including generics and fuzz testing). Libraries can get prepared for the release by supporting and exploring new features in advance, this also helps gaining preliminary experience.

Standard GitHub Action actions/setup-go allows using pre-releases with stable: false flag.

Example:

jobs:
  test:
    strategy:
      matrix:
        go-version: [ 1.16.x, 1.17.x, 1.18.0-rc1 ]
    runs-on: ubuntu-latest
    steps:
      - name: Install Go
        uses: actions/setup-go@v2
        with:
          stable: false
          go-version: ${{ matrix.go-version }}

In some cases you may want to run tests against gotip which is a head of development tree. Standard action does not support gotip, but it is easy to install it manually from build snapshots.

jobs:
  test:
    strategy:
      matrix:
        go-version: [ 1.16.x, 1.17.x, 1.18.0-rc1, tip ]
    runs-on: ubuntu-latest
    steps:
      - name: Install Go
        if: matrix.go-version != 'tip'
        uses: actions/setup-go@v2
        with:
          stable: false
          go-version: ${{ matrix.go-version }}
      - name: Install Go tip
        if: matrix.go-version == 'tip'
        run: |
          curl -sL https://storage.googleapis.com/go-build-snap/go/linux-amd64/$(git ls-remote https://github.com/golang/go.git HEAD | awk '{print $1;}').tar.gz -o gotip.tar.gz
          ls -lah gotip.tar.gz
          mkdir -p ~/sdk/gotip
          tar -C ~/sdk/gotip -xzf gotip.tar.gz
          ~/sdk/gotip/bin/go version
          echo "PATH=$HOME/go/bin:$HOME/sdk/gotip/bin/:$PATH" >> $GITHUB_ENV

The Install Go tip step here would download pre-built Go for a latest commit in master. There is a caveat though, for a very recent commit the build might be not finished by the time of download and this may result in CI failure. It does not happen very often and retry usually helps.

Tutorial: Developing a RESTful API with Go, JSON Schema validation and OpenAPI docs

Viacheslav Poturaev — Tue, 08 Feb 2022 23:32:18 +0000

This tutorial continues Developing a RESTful API with Go and Gin featured in Go documentation. Please check it first.

TL;DR We're going to replace gin-gonic/gin with swaggest/rest to obtain type-safe OpenAPI spec with Swagger UI and JSON Schema request validation.

Providing reliable and accurate documentation becomes increasingly important thanks to growing integrations between the services. Whether those integrations are between your own microservices, or you are serving an API to 3rd party.

OpenAPI v3 is currently a dominating standard to describe REST API in machine-readable format. There is a whole ecosystem of tools for variety of platforms and languages that help automating integrations and documentation using OpenAPI schema. For example, 3rd party can generate SDK from schema to use your API.

Prerequisites

Let's start with the result of previous tutorial.



package main

import (
    "net/http"

    "github.com/gin-gonic/gin"
)

// album represents data about a record album.
type album struct {
    ID     string  `json:"id"`
    Title  string  `json:"title"`
    Artist string  `json:"artist"`
    Price  float64 `json:"price"`
}

// albums slice to seed record album data.
var albums = []album{
    {ID: "1", Title: "Blue Train", Artist: "John Coltrane", Price: 56.99},
    {ID: "2", Title: "Jeru", Artist: "Gerry Mulligan", Price: 17.99},
    {ID: "3", Title: "Sarah Vaughan and Clifford Brown", Artist: "Sarah Vaughan", Price: 39.99},
}

func main() {
    router := gin.Default()
    router.GET("/albums", getAlbums)
    router.GET("/albums/:id", getAlbumByID)
    router.POST("/albums", postAlbums)

    router.Run("localhost:8080")
}

// getAlbums responds with the list of all albums as JSON.
func getAlbums(c *gin.Context) {
    c.JSON(http.StatusOK, albums)
}

// postAlbums adds an album from JSON received in the request body.
func postAlbums(c *gin.Context) {
    var newAlbum album

    // Call BindJSON to bind the received JSON to
    // newAlbum.
    if err := c.BindJSON(&newAlbum); err != nil {
        return
    }

    // Add the new album to the slice.
    albums = append(albums, newAlbum)
    c.JSON(http.StatusCreated, newAlbum)
}

// getAlbumByID locates the album whose ID value matches the id
// parameter sent by the client, then returns that album as a response.
func getAlbumByID(c *gin.Context) {
    id := c.Param("id")

    // Loop through the list of albums, looking for
    // an album whose ID value matches the parameter.
    for _, a := range albums {
        if a.ID == id {
            c.JSON(http.StatusOK, a)
            return
        }
    }
    c.JSON(http.StatusNotFound, gin.H{"message": "album not found"})
}

Initialize web service

Let's update main function to use a web service for our use case interactors, it will be capable of collecting automated documentation and applying request validation.

Also we can provide basic information about our API using type-safe OpenAPI bindings.



func main() {
    service := web.DefaultService()

    service.OpenAPI.Info.Title = "Albums API"
    service.OpenAPI.Info.WithDescription("This service provides API to manage albums.")
    service.OpenAPI.Info.Version = "v1.0.0"

Add web to imports.



    "github.com/swaggest/rest/web"

Upgrade a handler to return all items

In order to express more information about our http handler, we need refactor it to a use case interactor.

The constructor usecase.NewInteractor takes a generic interact function that should be called for input and prepare data at output pointer.

When web service receives request it will determine correct use case based on route and will prepare instances of input and output for further interaction (call of a function).

Input instance will be filled with data from http request, output instance will be created as a pointer to new output value.

In this case we don't need any request parameters, so input type can be struct{}.

This action will provide a list of albums. So the output type would be a pointer to slice of albums *[]album.



func getAlbums() usecase.Interactor {
    u := usecase.NewInteractor(func(ctx context.Context, _ struct{}, output *[]album) error {
        *output = albums
        return nil
    })
    u.SetTags("Album")

    return u
}

Input and output types are most important for automated http mapping and documentation generation. You can provide more information for the use case, for example tags to group multiple use cases together.

Now we can add upgraded use case to web service (in main function).



    service.Get("/albums", getAlbums())

Upgrade a handler to create new item

In this case we receive input as a JSON payload of album, so input type would be album.

We also return received album in response, so the output would be *album.

Output instance is provided as a placeholder for data, so it has to be a pointer. In contrast, input is not used after interact function is invoked, so it can be a non-pointer value.



func postAlbums() usecase.Interactor {
    u := usecase.NewInteractor(func(ctx context.Context, input album, output *album) error {
        // Add the new album to the slice.
        albums = append(albums, input)

        *output = input
        return nil
    })
    u.SetTags("Album")

    return u
}

Let's implement additional logic in this use case, to restrict id duplicates in the albums. In such case we can return conflict error.



func postAlbums() usecase.Interactor {
    u := usecase.NewInteractor(func(ctx context.Context, input album, output *album) error {
        // Check if id is unique.
        for _, a := range albums {
            if a.ID == input.ID {
                return status.AlreadyExists
            }
        }

        // Add the new album to the slice.
        albums = append(albums, input)

        *output = input
        return nil
    })
    u.SetTags("Album")
    u.SetExpectedErrors(status.AlreadyExists)

    return u
}

As you can see, we've also added u.SetExpectedErrors(status.AlreadyExists) to inform documentation collector that this use case may fail in a particular way.

Now we can add the upgraded use case to web service (in main function).



    service.Post("/albums", postAlbums(), nethttp.SuccessStatus(http.StatusCreated))

Mind the additional option that changes successful status from default http.StatusOK to http.StatusCreated. This fine control is left outside of use case definition because it is specific to http, use case interactor can potentially be used with other transports (see Clean Architecture for more details on this concept).

Add validation to `album` structure

Now let's add some validation rules to our album structure.



// album represents data about a record album.
type album struct {
    ID     string  `json:"id" required:"true" minLength:"1" description:"ID is a unique string that determines album."`
    Title  string  `json:"title" required:"true" minLength:"1" description:"Title of the album."`
    Artist string  `json:"artist,omitempty" description:"Album author, can be empty for multi-artist compilations."`
    Price  float64 `json:"price" minimum:"0" description:"Price in USD."`
}

Validation rules can be added with field tags (or special interfaces). Along with validation rules you can supply brief descriptions of field values.

ID is a required field that can not be empty,
Title as well,
Artist is an optional field,
Price can't be negative.

Validation is powered by JSON Schema.

Upgrade a handler to return specific item

In this case we need to read request parameter from URL path. For that our input structure should contain a field with path tag to enable data mapping.

Given this use case can end up with Not Found status, we add the status to expected errors for documentation. We also wrap the error in use case body to have a correct http status.



func getAlbumByID() usecase.Interactor {
    type getAlbumByIDInput struct {
        ID string `path:"id"`
    }

    u := usecase.NewInteractor(func(ctx context.Context, input getAlbumByIDInput, output *album) error {
        for _, album := range albums {
            if album.ID == input.ID {
                *output = album
                return nil
            }
        }
        return status.Wrap(errors.New("album not found"), status.NotFound)
    })
    u.SetTags("Album")
    u.SetExpectedErrors(status.NotFound)

    return u
}

Now we can add this use case to web service (in main function).



    service.Get("/albums/{id}", getAlbumByID())

Mind the path placeholder has changed from :id to {id} to comply with OpenAPI standard.

Mount Swagger UI

You can add a web interface to the API with Swagger UI.



    service.Docs("/docs", v4emb.New)

Add v4emb to imports.



    "github.com/swaggest/swgui/v4emb"

Then documentation will be served at http://localhost:8080/docs.

Resulting program



package main

import (
    "context"
    "errors"
    "log"
    "net/http"

    "github.com/swaggest/rest/nethttp"
    "github.com/swaggest/rest/web"
    "github.com/swaggest/swgui/v4emb"
    "github.com/swaggest/usecase"
    "github.com/swaggest/usecase/status"
)

// album represents data about a record album.
type album struct {
    ID     string  `json:"id" required:"true" minLength:"1" description:"ID is a unique string that determines album."`
    Title  string  `json:"title" required:"true" description:"Title of the album."`
    Artist string  `json:"artist,omitempty" description:"Album author, can be empty for multi-artist compilations."`
    Price  float64 `json:"price" minimum:"0" description:"Price in USD."`
}

// albums slice to seed record album data.
var albums = []album{
    {ID: "1", Title: "Blue Train", Artist: "John Coltrane", Price: 56.99},
    {ID: "2", Title: "Jeru", Artist: "Gerry Mulligan", Price: 17.99},
    {ID: "3", Title: "Sarah Vaughan and Clifford Brown", Artist: "Sarah Vaughan", Price: 39.99},
}

func main() {
    service := web.DefaultService()

    service.OpenAPI.Info.Title = "Albums API"
    service.OpenAPI.Info.WithDescription("This service provides API to manage albums.")
    service.OpenAPI.Info.Version = "v1.0.0"

    service.Get("/albums", getAlbums())
    service.Get("/albums/{id}", getAlbumByID())
    service.Post("/albums", postAlbums(), nethttp.SuccessStatus(http.StatusCreated))

    service.Docs("/docs", v4emb.New)

    log.Println("Starting service")
    if err := http.ListenAndServe("localhost:8080", service); err != nil {
        log.Fatal(err)
    }
}

func getAlbums() usecase.Interactor {
    u := usecase.NewInteractor(func(ctx context.Context, _ struct{}, output *[]album) error {
        *output = albums
        return nil
    })
    u.SetTags("Album")

    return u
}

func postAlbums() usecase.Interactor {
    u := usecase.NewInteractor(func(ctx context.Context, input album, output *album) error {
        // Check if id is unique.
        for _, a := range albums {
            if a.ID == input.ID {
                return status.AlreadyExists
            }
        }

        // Add the new album to the slice.
        albums = append(albums, input)

        *output = input
        return nil
    })
    u.SetTags("Album")
    u.SetExpectedErrors(status.AlreadyExists)

    return u
}

func getAlbumByID() usecase.Interactor {
    type getAlbumByIDInput struct {
        ID string `path:"id"`
    }

    u := usecase.NewInteractor(func(ctx context.Context, input getAlbumByIDInput, output *album) error {
        for _, album := range albums {
            if album.ID == input.ID {
                *output = album
                return nil
            }
        }
        return status.Wrap(errors.New("album not found"), status.NotFound)
    })
    u.SetTags("Album")
    u.SetExpectedErrors(status.NotFound)

    return u
}

Tidy modules and start the app!

In order to download necessary modules run go mod tidy in the directory of your module.

Then run the app with go run main.go and open http://localhost:8080/docs.

OpenAPI schema will be available at http://localhost:8080/docs/openapi.json.

openapi.json



{
 "openapi": "3.0.3",
 "info": {
  "title": "Albums API",
  "description": "This service provides API to manage albums.",
  "version": "v1.0.0"
 },
 "paths": {
  "/albums": {
   "get": {
    "tags": [
     "Album"
    ],
    "summary": "Get Albums",
    "description": "",
    "operationId": "getAlbums",
    "responses": {
     "200": {
      "description": "OK",
      "content": {
       "application/json": {
        "schema": {
         "type": "array",
         "items": {
          "$ref": "#/components/schemas/Album"
         }
        }
       }
      }
     }
    }
   },
   "post": {
    "tags": [
     "Album"
    ],
    "summary": "Post Albums",
    "description": "",
    "operationId": "postAlbums",
    "requestBody": {
     "content": {
      "application/json": {
       "schema": {
        "$ref": "#/components/schemas/Album"
       }
      }
     }
    },
    "responses": {
     "201": {
      "description": "Created",
      "content": {
       "application/json": {
        "schema": {
         "$ref": "#/components/schemas/Album"
        }
       }
      }
     },
     "409": {
      "description": "Conflict",
      "content": {
       "application/json": {
        "schema": {
         "$ref": "#/components/schemas/RestErrResponse"
        }
       }
      }
     }
    }
   }
  },
  "/albums/{id}": {
   "get": {
    "tags": [
     "Album"
    ],
    "summary": "Get Album By ID",
    "description": "",
    "operationId": "getAlbumByID",
    "parameters": [
     {
      "name": "id",
      "in": "path",
      "required": true,
      "schema": {
       "type": "string"
      }
     }
    ],
    "responses": {
     "200": {
      "description": "OK",
      "content": {
       "application/json": {
        "schema": {
         "$ref": "#/components/schemas/Album"
        }
       }
      }
     },
     "404": {
      "description": "Not Found",
      "content": {
       "application/json": {
        "schema": {
         "$ref": "#/components/schemas/RestErrResponse"
        }
       }
      }
     }
    }
   }
  }
 },
 "components": {
  "schemas": {
   "Album": {
    "required": [
     "id",
     "title"
    ],
    "type": "object",
    "properties": {
     "artist": {
      "type": "string",
      "description": "Album author, can be empty for multi-artist compilations."
     },
     "id": {
      "minLength": 1,
      "type": "string",
      "description": "ID is a unique string that determines album."
     },
     "price": {
      "minimum": 0,
      "type": "number",
      "description": "Price in USD."
     },
     "title": {
      "type": "string",
      "description": "Title of the album."
     }
    }
   },
   "RestErrResponse": {
    "type": "object",
    "properties": {
     "code": {
      "type": "integer",
      "description": "Application-specific error code."
     },
     "context": {
      "type": "object",
      "additionalProperties": {},
      "description": "Application context."
     },
     "error": {
      "type": "string",
      "description": "Error message."
     },
     "status": {
      "type": "string",
      "description": "Status text."
     }
    }
   }
  }
 }
}

Source code.

P.S. Original tutorial has a race condition on albums, this is not fixed here as out of scope of the article, but please be aware. :)