linusdm

linusdm

Simplify adding production-grade logging to your standard Phoenix webapp

I’m prepping a go-live for a LiveView application we’ve been working on for months now. One of the things I’ve spent more time on than expected was getting the logs just right. It took me some time to realise that modern libraries/frameworks like Phoenix and Oban expect you to hook into the Telemetry events for logging and error reporting.

I’m under the impression that setting up logging for production use is an underserved aspect of shipping a Phoenix application. The logs for development are great. It contains all the correct log messages, in a human readable format (and now even streams to the browser console too). Not too much, not too little, and without any fiddling. Great! For production use, this setup doesn’t seem usable though. I can imagine everybody having a slightly different preference here, but still, I wasn’t expecting having to delve into all these different helper packages to whip up a working solution.

At first I was hopeful that Logster was going to be my one-stop solution for this. This library was inspired by the Ruby Lograge package. But it turns out it’s doing its own encoding into the logfmt format. Although I like the logfmt format, it’s difficult to make sure other libraries that are not instrumented by Logster produce a similar structure. I like the library for having an opinion on which logs are useful 95% of the time. But I don’t like that it also takes on the responsibility of formatting the messages. I think it’s more idiomatic to defer formatting decisions to the Logger.Formatter system.

We’re also using Oban, which requires its own handlers for logging and error reporting. In the end I settled on hooking up my own handlers for all the relevant Telemetry events. But I’m sure I’m missing some important ones, as I’m not really experienced with this operational concern.

Is everybody having a similar struggle? If so, this might indicate that there is still some room for improvement, so that sensible (opinionated) production-grade logging can be added easily to any project, in a matter of minutes. That probably would have saved me a lot of hours researching this, and piecing together the packages.

I’m curious to learn about how other people are tackling this aspect, and how you think things might be improved. Please let me know if I’m missing something obvious here!

Most Liked

ibarch

ibarch

Sure, but I’m afraid you’ll still have to investigate OpenTelemetry spec and configuration unless you have a dedicated team for that purpose.

First, you need to add systemd (kudos to @hauleth for such a great library) to the project.

Add default (previously known as console) formatter to config.exs:

config :logger,
  level: :info,
  default_formatter: [
    format: "$metadata[$level] $message\n",
    metadata: [:request_id]
  ]

Disable default formatter in prod environment in runtime.exs:

if config_env() == :prod do
  # INVOCATION_ID should be set automatically by systemd
  # If the app is being run outside of systemd we keep the default handler
  if System.get_env("INVOCATION_ID") do
    config :logger, default_handler: false

    config :my_app, :logger, [
      # this handler implements journald protocol for structured logs 
      {:handler, :systemd, :systemd_journal_h,
       %{
         config: %{
           fields: [
             # default metadata
             :syslog_timestamp,
             :level,
             :priority,
             {"SYSLOG_IDENTIFIER", ~c"my_app"},
             {"SERVICE_VERSION", System.get_env("RELEASE_VSN")},
             # custom metadata
             :request_id,
             :current_user_id,
             :my_other_var
           ]
         },
         formatter:
           Logger.Formatter.new(format: "$metadata[$level] $message", metadata: [:request_id])
       }}
    ]
  end
end

Add the new journald log handler in application.ex:

def start(_type, _args) do
  Logger.add_handlers(:my_app)

  children =
    [
      ...
      :systemd.ready()
    ]

  opts = [strategy: :one_for_one, name: MyApp.Supervisor]
  Supervisor.start_link(children, opts)
end

We’re done with the Elixir’s part of the puzzle. Open ssh connection to the target machine and verify that logging works as expected:

# verify that REQUEST_ID and other fields are present
journalctl --unit my_app --reverse --output verbose

# filter by :emergency, :alert, :critical and :error priority levels
journalctl --unit my_app --priority 0..3

# filter by REQUEST_ID field
journalctl --unit my_app REQUEST_ID=0c3a38d5b7b3731863490d9de68a77c5

If it does then proceed with installing OpenTelemetry Collector Contrib. I have an Ansible role for that, but skipped posting it for brevity. Let me know if you’re interested.

Otel Collector config in /etc/otelcol-contrib/config.yaml could look like:

receivers:
  journald:
    units:
      - my_app
    operators:
      - type: severity_parser
        parse_from: body.LEVEL
        preset: none
        mapping:
          debug: debug
          info: info
          info2: notice
          warn: warning
          error: error
          error2: critical
          fatal: alert
          fatal2: emergency
      - type: move
        from: body
        to: attributes.body
      - type: flatten
        field: attributes.body
      - type: move
        from: attributes.MESSAGE
        to: body
      - type: move
        from: attributes._HOSTNAME
        to: resource.host.name
      - type: move
        from: attributes.SYSLOG_IDENTIFIER
        to: resource.service.name
      - type: move
        from: attributes.SERVICE_VERSION
        to: resource.service.version
  otlp:
    protocols:
      http:
        endpoint: "localhost:4318"

exporters:
  otlphttp/openobserve:
    endpoint: https://api.openobserve.ai/api/my_organization_123
    headers:
      Authorization: Basic foobar=
      stream-name: default

processors:
  attributes:
    actions:
      - pattern: ^_.+
        action: delete
      - pattern: ^SYSLOG_.+
        action: delete
      - pattern: ^CODE_.+
        action: delete
      - key: PRIORITY
        action: delete
      - key: LEVEL
        action: delete
  transform:
    error_mode: ignore
    log_statements:
      - context: log
        statements:
          - replace_pattern(body, "^.*\\[.+\\] ", "")
  batch:

extensions:
  health_check:

service:
  extensions: [health_check]
  pipelines:
    logs:
      receivers: [journald]
      processors: [attributes, transform, batch]
      exporters: [otlphttp/openobserve]
      # add traces and metrics here
dimitarvp

dimitarvp

The easy way out is to limit production logging to the :info level while having everything else be at :debug?

D4no0

D4no0

Personally I think that using logs in text format is by far not the best solution when it comes on keeping visibility of the system.

Besides the fact that if you log a lot of things you will reach a point where you will start losing logs because the system will not be able to persist them so fast, you also have a big mess of text logs afterwards that you have navigate through and somehow make sense of them.

I have used metrics and time series databases like InfluxDB before to have a much better outcome when it comes to visibility on system/subsystems and introspection. This also goes perfectly hand-to-hand with how telemetry in elixir works, because I can decide ultimately the shape of output data.

If you are set on just outputting text from your telemetry events to console logs, just make a generic handler that will just log everything, should be no more than 10 lines of code.

Where Next?

Popular in Discussions Top

Jayshua
I recently came across the javascript library htmx. It reminded me a lot of liveview so I thought the community here might be interested....
New
Nvim
Anybody knows a comprehensive comparison of Django and Phoenix, thanks for the help. Where are they similar? Where do they differ the m...
New
jeramyRR
This is an interesting article to read. Elixir’s performance, like usual, is excellent. However, it seems like the high CPU usage is co...
New
cvkmohan
The upcoming Phoenix 1.6 release looks very interesting. Became a habit to watch the commits - and - what they are bringing in. phx.gen...
New
laiboonh
Hi all, I am trying to convince my team to use liveview over the current react. What are some of the points where one should consider us...
New
fireproofsocks
I’ve been working on an Elixir project that has required a lot of scripting. I usually reach for Elixir because I like it more (and in th...
New
hazardfn
I suppose this question is effectively hackney vs. ibrowse but we are at a point in our project where we have to make a choice between th...
New
restack_oslo
Hello, Please pardon me for any faux paux. I am 46 and this is my first time on a forum of any kind. I wanted to to get answers from tho...
New
MarioFlach
Hello, I want to share a project I’ve been working on for a while: https://github.com/almightycouch/gitgud Background Some time ago I ...
New
Qqwy
Looking at the stacks that existing large companies have used, WhatsApp internally uses Mnesia to store the messages, while Discord uses ...
New

Other popular topics Top

malloryerik
Hi, this is for people who, like me, have had some friction using .html.heex templates in VSCode. The solution seems to be, in a hyphena...
New
stefanluptak
Hello everybody, usually, I use a 29" ultra-wide monitor for VSCode which can easily accomodate explorer (files panel) + file with code ...
New
sen
Hi All, I set a environment variables in dev.exs , like below code. when i start server, how can i set the ${enable} value? thanks. d...
New
stefanchrobot
What’s the safe way to decode a JSON string into a struct? I want to avoid calling String.to_atom. Jason.decode can give me a map with st...
New
bsollish-terakeet
Credo is smart enough to check for (something like) this: assert length(the_list) == 0 with this response: Checking if an enum is empt...
New
saif
Hello everyone, Long time lurker first time poster here. I’ve recently begun working on Elixir full-time again! :raised_hands: It’s been...
New
shijith.k
I am trying to start a new phoenix project with elixir 1.9, but mix phx.new does not work. It says that ** (Mix) The task "phx.new" could...
New
openscript
Hello! Sorry for this astonishing simple question, but I’m really stuck. I try to set up the intellij-elixir plugin, but I don’t know ho...
New
dokuzbir
I want to highlight html closing tags when i click a html tag. That works in .html files but doesnt work for html.eex templates. How can...
New
senggen
Erlang/OTP 25 [erts-13.2.2] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] 15:22:35.803 [error] gen_event {lager_file_backend...
New

We're in Beta

About us Mission Statement