Current section

Files

Jump to
Raw

README.md

# ClickhouseExLogger

Ship Elixir [`Logger`](https://hexdocs.pm/logger/Logger.html) events into
ClickHouse, through [Ash](https://hexdocs.pm/ash) and
[AshClickhouse](https://hexdocs.pm/ash_clickhouse), so they land in a table you
can `SELECT` against instead of a file you have to grep.

Logging stays non-blocking: `Logger.info/1` formats a row and hands it to a
buffer process. Batches are written with one insert each. If ClickHouse is slow
or down, the oldest buffered rows are discarded and counted — your application
never blocks and never runs out of memory.

## Installation

```elixir
def deps do
  [{:clickhouse_ex_logger, "~> 0.1.0"}]
end
```

## Setup

Three steps. There is no application code to write: the library starts its own
pipeline when your application starts.

**1. Configure the connection.**

```elixir
# config/runtime.exs
config :clickhouse_ex_logger, ClickhouseExLogger.Repo,
  url: System.get_env("CLICKHOUSE_URL", "http://localhost:8123"),
  username: System.get_env("CLICKHOUSE_USER", "default"),
  password: System.get_env("CLICKHOUSE_PASSWORD", ""),
  database: "my_app"
```

That key is required, and a missing one is an error rather than a default:

```
** (AshClickhouse.Error.ConfigurationError) ClickhouseExLogger.Repo is not configured.
```

Without the check it would fall back to `http://localhost:8123` and quietly
write your logs somewhere you did not choose — or report every flush as failed,
which looks like a ClickHouse outage rather than a configuration mistake.

`username:` and `password:` authenticate the connection, as written — no URL
surgery in your `runtime.exs`. Against a password-protected server that is the
only change you need:

```sh
export CLICKHOUSE_URL=http://clickhouse.internal:8123
export CLICKHOUSE_USER=writer
export CLICKHOUSE_PASSWORD=...   # the password is percent-encoded for you
```

<details>
<summary>Upgrading from a version that ignored these keys</summary>

Before this, `:username` and `:password` were accepted and then discarded: the
data layer forwards only `:url`, and the client beneath it has no credential
option. A password-protected server answered every request with
`Code: 194 ... Authentication failed`, reported and counted as lost — the same
as an outage. If you worked around it by building the credentialed URL yourself
in `config/runtime.exs`, delete that: the library does it now.

If you would rather keep the old behaviour — a server that ignores
authentication, say — put the credentials in the URL instead. A URL that already
carries them is used verbatim, and `:username`/`:password` are then ignored:

```elixir
config :clickhouse_ex_logger, ClickhouseExLogger.Repo,
  url: "http://writer:s3cret@clickhouse.internal:8123",
  database: "my_app"
```

</details>

**2. Create the schema.** Run this from your application *before* you start it, so
the first flush has somewhere to go.

```sh
mix clickhouse_ex_logger.migrate
```

It creates the database if it is missing and the `logs` table if it is not, and
is safe to re-run. To see what it would do without changing anything:

```sh
mix clickhouse_ex_logger.migrate --dry-run
```

In a release — where there is no Mix and no `mix` on the machine — call the same
operation instead:

```sh
bin/my_app eval "ClickhouseExLogger.Utils.migrate()"
bin/my_app eval "ClickhouseExLogger.Utils.migrate(dry_run: true)"
```

Both do exactly the same thing: same migrations, same files shipped in
`priv/repo/migrations`, same connection configuration. Run either *before* the
new version starts logging.

> **Upgrading an existing deployment? Run this again.** A later version of this
> library writes a `node` column that tables created by an earlier version do not
> have, and ClickHouse rejects the whole batch — `No such column node in table`.
> Nothing raises in your application; the rows are simply counted as `lost`. So
> run this command as part of the deploy, *before* the new version starts
> logging. The command is the same one you already run; you just have to run it
> again — `mix clickhouse_ex_logger.migrate` from a checkout, or
> `bin/my_app eval "ClickhouseExLogger.Utils.migrate()"` from a release.

> Use this task, not `mix ash_clickhouse.migrate`. That task finds AshClickhouse
> resources by listing the modules of the *current* project, so it never sees
> `ClickhouseExLogger.LogEntry` — that resource belongs to this dependency.

**3. Start logging.**

That is the whole setup. Starting your application starts the ClickHouse
connection and attaches the handler; there is nothing to add to your supervision
tree and nothing to call.

The library reads one thing at startup that is worth knowing about. It checks
whether the `logs` table exists before it attaches:

- **Table is there** — the handler attaches. This is the normal case.
- **Server does not answer** — the handler attaches anyway, and delivery failures
  are reported and counted like any other. A ClickHouse that is briefly down at
  boot does not turn your logging off.
- **Table is missing** — the handler does *not* attach, and you get one error
  naming `mix clickhouse_ex_logger.migrate`. This is the "you forgot step 2" case,
  and you get a sentence rather than a `lost` count that looks like an outage.
  Create the table and restart.

Read the check itself: it is one `SELECT count()` against `system.tables`. Nothing
is created or altered at boot, ever — see
[`ClickhouseExLogger.Migration`](https://hexdocs.pm/clickhouse_ex_logger/ClickhouseExLogger.Migration.html).

### Upgrading from 0.2.x

0.3.0 starts the pipeline itself. **If your application supervises
`ClickhouseExLogger.Repo`, add this to your configuration before you upgrade:**

```elixir
config :clickhouse_ex_logger, auto_start: false
```

Without it your application will not boot:

```
** (EXIT from #PID<0.123.0>) shutdown: failed to start child: ClickHouse.Interface.HTTP
    ** (EXIT) an exception was raised:
        ** (ArgumentError) errors were found at the given arguments:
          * 1st argument: table name already exists
```

A ClickHouse client keeps a globally named ETS table per connection, so a second
connection under the same name cannot be started — the client raises from inside
the new process, and your supervisor takes the failure. This library starts the
connection; your supervision tree would be starting the same one.

With `auto_start: false` your existing code works unchanged: keep
`ClickhouseExLogger.Repo` in your children and your
`ClickhouseExLogger.Handler.install/2` call exactly as they are. Nothing else
about 0.2.x's setup changed. If you had no application code, delete nothing —
just upgrade.

## Configuration

All keys are optional except the connection block above.

### The connection

Set once, under `config :clickhouse_ex_logger, ClickhouseExLogger.Repo`. The
supported keys are those of `AshClickhouse.Repo`: `:url`, `:username`,
`:password`, `:database`, `:pool_size`, and `:ipv4_only`.

| Key | Meaning |
| --- | --- |
| `:url` | ClickHouse HTTP endpoint, e.g. `"http://localhost:8123"`. |
| `:username` | Authenticates as this user. A value other than `"default"` is sent even with no password. |
| `:password` | Sent as the password. Percent-encoded into the URL, so `@` and `:` need no escaping. |
| `:database` | Database holding the `logs` table. |

A URL that already carries credentials — `http://user:pass@host:8123` — is used
as-is and the two keys above are ignored. Omitting `:username` alongside a
`:password` authenticates as `default`. Leaving both at their defaults sends no
credentials at all, which is what a password-less local ClickHouse wants.

### `:auto_start`

| Key | Default | Meaning |
| --- | --- | --- |
| `:auto_start` | `true` | Whether the library starts the pipeline itself. See [Upgrading from 0.2.x](#upgrading-from-02x). |

### `:handler`

The options the automatically-started handler uses. Same options, same
validation, same defaults as the table below:

```elixir
config :clickhouse_ex_logger, handler: [level: :info, batch_size: 500]
```

| Key | Default | Meaning |
| --- | --- | --- |
| `:level` | `:all` | Minimum level to ship. `:logger` filters on this. |
| `:batch_size` | `500` | Buffered rows that trigger a write. |
| `:flush_interval_ms` | `1_000` | How often to write a partial batch. |
| `:max_buffer_size` | `10_000` | Hard cap on buffered rows. |
| `:include_node` | `true` | Record the node name on each row. See [below](#node-tells-you-which-machine). |

`:batch_size` is a **trigger, not a cap**: a write always takes everything
buffered, so a slow write lets rows accumulate rather than leaving a remainder
behind.

A value that is not a positive integer fails the start with an error naming the
option, rather than failing later during delivery. A non-boolean `:include_node`
fails the same way.

`:include_node` is a *handler* option rather than a batching one, so it does not
appear in `Buffer.options()`.

## Starting it yourself

`Handler.install/2` and `Handler.uninstall/1` are still there, and still what the
automatic start calls. Reach for them when you set `:auto_start` to `false` and
want the same behaviour from your own code:

```elixir
def start(_type, _args) do
  children = [
    ClickhouseExLogger.Repo,
    MyAppWeb
    # ...
  ]

  with {:ok, pid} <- Supervisor.start_link(children, strategy: :one_for_one, name: MyApp.Supervisor) do
    :ok = ClickhouseExLogger.Handler.install(:clickhouse_ex_logger, batch_size: 500)
    {:ok, pid}
  end
end
```

`Handler.install/2` registers the `:logger` handler and starts the batching
buffer. `Handler.uninstall/1` removes the handler and flushes what is still
buffered, so call it from your shutdown path if you have one:

```elixir
ClickhouseExLogger.Handler.uninstall(:clickhouse_ex_logger)
```

`Handler.install/2` is idempotent where it matters: a running buffer is reused
rather than duplicated, and an already-registered handler id is not registered
twice. So calling it while the automatic start has already attached does not give
you two handlers or two writers.

### Declarative registration

You can also register through `:logger` directly:

```elixir
config :my_app, :logger,
  handler: [
    {:handler, :clickhouse_ex_logger, ClickhouseExLogger.Handler,
     %{batch_size: 500, flush_interval_ms: 1_000, max_buffer_size: 10_000}}
  ]
```

then `Logger.add_handlers(:my_app)` from `Application.start/2`.

Prefer `Handler.install/2`. Declarative registration hands the config straight to
`:logger`, which neither validates it nor gives this library a hook to flush on
removal — so a typo in `:batch_size` shows up as a misbehaving buffer rather than
an error at boot, and removing the handler discards whatever was buffered.

## The `logs` table

| Column | ClickHouse type | Meaning |
| --- | --- | --- |
| `id` | `UUID` | Unique identifier for the row |
| `timestamp` | `DateTime64(6)` | When the event was logged (UTC) |
| `level` | `String` | Erlang severity, e.g. `"info"` |
| `message` | `String` | The rendered log message |
| `module` | `Nullable(String)` | Calling module |
| `file` | `Nullable(String)` | Calling file |
| `line` | `Nullable(Int64)` | Calling line |
| `function` | `Nullable(String)` | Calling function/arity |
| `metadata` | `Map(String, String)` | Log metadata, values stringified |
| `node` | `Nullable(String)` | Node that handled the event, or `NULL` |

### `node` tells you which machine

Every row records the node that handled it — `my_app@10.0.0.5`, the full name, so
two applications sharing a host stay distinguishable. That is what makes
`WHERE node = 'my_app@10.0.0.5'` answer "which instance threw this".

It is `NULL` in two cases, and both are deliberate:

- **The system is not distributed** — a local `iex -S mix`, or the test suite,
  where the node is `:nonode@nohost`. There is no host to report, and a stored
  `nonode@nohost` is indistinguishable from a real host at a glance.
- **The host disabled capture** with `:include_node: false`.

So distributed rows are filterable in one step:

```sql
SELECT node, count() FROM logs WHERE node IS NOT NULL GROUP BY node
```

Turning the option off writes `NULL`; it does not remove the column. The schema is
the same either way, so a query written against `node` keeps working and turning
capture back on needs no migration.

`ENGINE = MergeTree()`, `ORDER BY (timestamp)` — so time-range queries prune
parts. Read rows back with plain SQL, or with Ash:

```elixir
ClickhouseExLogger.LogEntry
|> Ash.Query.filter(level == :error)
|> Ash.Query.sort(timestamp: :desc)
|> Ash.Query.limit(20)
|> Ash.read!()
```

### Two things about `id`

It is an identifier, not a uniqueness constraint. ClickHouse deduplicates by
*sorting key*, not by primary key, so it will happily store two rows with the same
`id`. It exists so you can cross-reference a specific row.

### Metadata values are strings

The column is `Map(String, String)`, so `ClickhouseExLogger.Event` renders every
value as text. Binaries pass through; other scalars go through `to_string/1`;
compound terms are stored as `inspect/1` output behind a `"term:"` marker so they
can be told apart from a genuine string and read back:

```elixir
"term:[1, 2]"
|> String.replace_prefix("term:", "")
|> Code.eval_string()
#=> {1, 2}, [1, 2]
```

Erlang's own event keys (`:mfa`, `:file`, `:line`, `:time`, …) are lifted into
their own columns and deliberately left out of the metadata map.

## Observing the pipeline

```elixir
ClickhouseExLogger.Buffer.stats()
#=> %{
#=>   accepted: 12_480,   # rows taken from the handler
#=>   delivered: 12_470,  # rows ClickHouse confirmed
#=>   discarded: 10,      # rows dropped because the buffer was full
#=>   lost: 0,            # rows ClickHouse did not accept, after a failed write
#=>   failed: 0,          # flushes that failed
#=>   buffered: 0,        # rows waiting right now
#=>   active?: true       # the buffer is running and accepting
#=> }
```

Read these as follows:

- **`accepted == delivered + discarded + lost`**, exactly, once nothing is in
  flight. Every row the handler accepted is accounted for. A `discarded` count
  that climbs means logging outpaces ClickHouse; a `lost` count that climbs
  means ClickHouse refused rows.
- **`discarded`** counts rows dropped oldest-first, so the buffer stays bounded.
- **`lost`** counts rows a failed write did not get accepted. One flush is
  several inserts, and the ones before a failure are already committed, so this
  is counted per row rather than per flush.
- **`failed` counts flushes, not rows.** One bad batch is one failure no matter
  how many rows it held.
- **`active?: false`** means the buffer is not running — the handler will keep
  accepting events and dropping them.

A failed write logs one error, marked so it does not become a row itself:

```
ClickhouseExLogger: dropped 500 buffered log row(s); the ClickHouse insert failed: …
```

Nothing is retried. A log pipeline that queues behind a database turns a
downstream outage into an upstream memory leak.

## Development

The suite starts its own ClickHouse, in a container, so you need a container
engine and nothing else:

```sh
podman machine start      # or start Docker Desktop
mix test
```

`test/test_helper.exs` provisions the container, waits for it, creates the
schema, and points the suite at it. There is nothing to start by hand.

If no engine is reachable, `mix test` fails and says so. It does not skip the
ClickHouse-backed tests: a suite that quietly excludes the tests proving the
pipeline survives a stalled database is worse than one that tells you it cannot
run. The four modules that need no database still pass without an engine
(`mix test test/clickhouse_ex_logger/event_test.exs` and friends).

The container is reused between runs, so only the first one pays ClickHouse's
startup. To remove it:

```sh
podman rm -f $(podman ps -q --filter ancestor=clickhouse/clickhouse-server:26.9)
```

Set `CONTAINER_ENGINE_HOST` if your engine's socket is somewhere
`testcontainer_ex` does not look — with `podman machine` this is already handled,
but the socket path moves between machines and macOS releases. `CONTAINER_ENGINE`
forces a specific engine.

### Releasing

Releasing is a deliberate, manual act. `mix hex.publish` is irreversible in
practice: the name is taken on hex.pm, and anyone who published can be seen doing
so. Authenticate once with `mix hex.user auth`.

Run these in order. Each one catches something the next would otherwise ship.

```sh
mix test --cover      # 204 tests; lib/ is gated at 90% line coverage
mix docs              # must build with no warnings — Hex rebuilds this on publish
mix hex.build         # writes clickhouse_ex_logger-<version>.tar
```

Then read the file list `mix hex.build` prints, and confirm the two shipped
migrations are in it:

```
priv/repo/migrations/20260101000000_create_logs.exs
priv/repo/migrations/20261001000000_add_node_to_logs.exs
```

This is the step that matters most. `mix clickhouse_ex_logger.migrate` resolves its
migrations through `:code.priv_dir/1`, so a release whose manifest omits `priv`
installs cleanly, compiles cleanly, and then raises `{:error, :bad_name}` the first
time a host runs the migration — the one step every host must run before it can log
anything. `test/mix_project_test.exs` asserts the manifest covers what `lib/`
resolves, so `mix test` already fails if that regresses.

Push the tag before publishing, not after. The published documentation points its
per-module source links at `v<version>`, so the tag has to exist when Hex builds
the docs:

```sh
git tag -a v0.1.0 -m "v0.1.0"
git push origin main --tags
mix hex.publish
```

To publish documentation for a version already on hex.pm without republishing the
package, use `mix hex.publish docs`. A release can be withdrawn for one hour after
publication with `mix hex.publish --revert VERSION`.

## A note on `ash_clickhouse`

This library pins `ash_clickhouse ~> 0.7`. In 0.7.3 the data layer's
`Ash.bulk_create/4` cannot write to ClickHouse — it leaks Ash's internal bulk
options into the client option list, which the client rejects, and its
`DateTime64` encoding overflows. `ClickhouseExLogger.Insert` works around both
using the data layer's own public building blocks, so the resource stays the
single source of truth for the table and its encoding.

The workaround lives in one module and its docs name both defects. When
upstream fixes them, `ClickhouseExLogger.Insert` collapses to
`Ash.bulk_create/4` with no behavioural change. See
`ClickhouseExLogger.Insert`.

## License

Apache-2.0. See [LICENSE](LICENSE).