ClickhouseExLogger

Ship Elixir Logger events into ClickHouse, through Ash and AshClickhouse, 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

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.

# 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:

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

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

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

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:

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:

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.

If you want proof rather than an absence of surprise, ask the library:

ClickhouseExLogger.status()
#=> %{
#=>   handler_attached?: true,
#=>   buffer_active?: true,
#=>   last_start: {:attached, "ClickhouseExLogger: attached the `:logger` handler; …"},
#=>   stats: %{accepted: 0, delivered: 0, discarded: 0, lost: 0, failed: 0, buffered: 0},
#=>   boot_capture: %{active?: false, held: 0, dropped: 0}
#=> }

That is "my rows are on their way to ClickHouse", answered without reading a log, querying the table, or waiting on anything. See When no rows arrive for the same call on the paths that fail.

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.

Events logged while the application starts are held, not lost

Attaching the handler takes a moment — the check above has to answer first — and your own Application.start/2 logs inside exactly that window. Those events are captured from the moment this library's application starts and written with the first batch the handler ships, in the order they were logged. Nothing is written before the check answers, so a missing table still produces the one readable message above rather than a failed write.

The hold is bounded by your :max_buffer_size: past it the oldest held row is dropped to admit the newest, exactly as the buffer does, and the drop is reported once, naming how many rows were dropped and the bound. A dropped row is not added to the buffer's counters — it was never accepted — so the counters still reconcile exactly.

Two limits are worth knowing. Events logged before this library's application starts — by its dependencies, or by the VM's earliest boot — still reach only the console: a dependency has no hook earlier than its own start. And your console output is unchanged throughout: the hold adds a destination, it does not remove one.

While rows are being held, ClickhouseExLogger.status/0 says so: boot_capture.active? is true and held is how many rows are waiting, so you can tell "captured, waiting to be shipped" from "shipping now" without reading a log.

You do not need to configure :logger

There is no :logger configuration for this library, and none is missing if you have not written any. What a host reaches for in its place is config :logger, :default_handler, config: [file: …] — which configures Erlang's default handler, the one that prints to your console, and nothing else. It decides where that handler writes: standard output, or a rotating file. This library's handler is registered separately, alongside it, and is unaffected either way.

So if rows are not arriving, do not look for a :logger key to set. What that config does affect is where this library's own reports go — and a report you cannot see is indistinguishable from a library that works. Read When no rows arrive instead.

The reverse is also worth knowing: adding the block above does not switch anything on. It moves your console output into a file, which is why it sometimes looks like the thing that made logging work when in fact it made a message about logging visible somewhere you happened to be reading.

Dashboard

Dashboard with basic search/filter & analysis in this repo.

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:

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.

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

:handler

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

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

: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:

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:

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:

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

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:

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:

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:

"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

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.

When no rows arrive

Call one function rather than reading a log, comparing destinations, or guessing:

ClickhouseExLogger.status()
#=> %{
#=>   handler_attached?: true,
#=>   buffer_active?: true,
#=>   last_start: {:attached, "ClickhouseExLogger: attached the `:logger` handler; …"},
#=>   stats: %{accepted: 12_480, delivered: 12_470, discarded: 10, lost: 0,
#=>            failed: 0, buffered: 0, active?: true},
#=>   boot_capture: %{active?: false, held: 0, dropped: 0}
#=> }

Three of the fields answer "what is true now" and one answers "what did the start decide", and that split is what makes the causes below separable — they would otherwise look identical, because none of them accepts a row.

status/0 never contacts ClickHouse, so it works when ClickHouse is the thing that is broken — which is the moment you call it. The two cases a :logger configuration would have hidden are now unreachable by design: a start that did not attach writes its reason to the standard error stream as well as through the logger, so it is visible whether or not your config :logger, :default_handler sends console output to a file.

For the counters themselves, read stats/0 the way it is documented above: accepted == delivered + discarded + lost once nothing is in flight, so a gap you cannot explain is a row that was counted.

Development

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

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:

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.

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:

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

The library writes through the data layer's batched insert, Ash.bulk_create/4. Doing that needs two upstream fixes: the data layer must not leak Ash's internal bulk options into the client option list, and it must encode DateTime64 in the form ClickHouse's JSON insert accepts (a fractional-second number, not an integer tick count, which the JSON reader treats as seconds and overflows). Both are present in ash_clickhouse 0.7.5. The data layer's own failure logging is also at :debug there, so the library — not the dependency — is what reports a failed flush.

ClickhouseExLogger.Insert still chunks a flush and calls Ash.bulk_create/4 once per 1000-row chunk, rather than once for the whole flush. That is an accounting requirement, not a workaround: the data layer does not advertise :bulk_create_with_partial_success, so a single call cannot report how many rows an earlier chunk committed, and ClickhouseExLogger.Buffer credits delivered from exactly that count. See ClickhouseExLogger.Insert.

License

Apache-2.0. See LICENSE.