Runtime “warn once” strategy

I’m after ideas and suggestions on how to emit a message when a certain condition is met at runtime - but only once, the first time the condition is met.

My use case is this: in ex_cldr_numbers a number format like #,###.## is compiled into meta data at compile time for all known formats (there are a lot of them in CLDR).

Since formats can be arbitrary they can also be compiled at runtime and then processed. That’s expensive (doubles the execution time for formatting a number in typical cases). And since number formatting is often in a tight loop its something to be avoided.

Therefore I want to emit a message (probably via Logger.debug) when a format is going to be compiled. But only the first time that format is being compiled. Otherwise the risk is that the log output becomes far too noisy to be useful. Additional formats can be defined in configuration and hence pre-compiled, therefore knowing which ones aren’t pre-compiled helps decide if they should be configured.

I can imagine some scaffolding involving an ets table and a counter based upon the format (which is a binary). And in development mode that’s probably ok, the overhead won’t be much. But I’m not sure that’s a good production solution.

This warn_once idea has cropped up as an idea for me in a few other cases so I figure someone may already have a solid approach.

1 Like

As a preliminary question, have you considered generating modules and injecting the warn_once functionality in their before_compile callback? That should piggyback on the compiler’s ability to only compile those modules once (at runtime when you choose).

@dimitarvp thanks for chiming in. I try hard to do as much work at compile time. Here is the module in question (edited for brevity). Its perfectly acceptable to provide an arbitrary format string at runtime, the only issue being the potential of this being a performance bottleneck. It might not be in some use cases, but it will in others.

I could:

  1. Emit a log event for each time its used. Easy, but potentially noisy
  2. Emit a telemetry event. But its not really a metric so probably a perversion
  3. Encapsulate in runtime generated modules (but it doesn’t feel right to do so just for a single function call). I think this is what you meant?
  4. Find another low cost way to “warn once” at runtime. Very comfortable to make this a configurable option - and thereby emit no code and therefore no performance impact, if not required,
defmodule Cldr.Number.Backend.Decimal.Formatter do
  @moduledoc false

  def define_number_module(config) do
    alias Cldr.Number.Formatter.Decimal
    backend = config.backend

    quote location: :keep do
      defmodule Number.Formatter.Decimal do
        .....
        def to_string(number, format, options \\ [])

        def to_string(number, format, options) when is_binary(format) and is_list(options) do
          with {:ok, options} <- Options.validate_options(number, unquote(backend), options) do
            to_string(number, format, options)
          end
        end

        # Precompile the known formats and build the formatting pipeline
        # specific to this format thereby optimizing the performance.
        unquote(Decimal.define_to_string(backend))

        ....

        # For formats not precompiled we need to compile first
        # and then process. This will be slower than a compiled
        # format since we have to (a) compile the format and (b)
        # execute the full formatting pipeline.
        def to_string(number, format, %Options{} = options) when is_binary(format) do
          case Compiler.format_to_metadata(format) do
            {:ok, meta} ->
              --> warn_once("This format isn't precompiled and will be compiled in each formatting request"*
              meta = Decimal.update_meta(meta, number, unquote(backend), options)
              Decimal.do_to_string(number, meta, unquote(backend), options)

            {:error, message} ->
              {:error, {Cldr.FormatCompileError, message}}
          end
        end
      end
    end
  end
end
1 Like

Yes. I don’t think it’s a big deal though, they are not going to have source files and won’t get in anybody’s face. Don’t overthink it, I’d encourage you to try just this approach — although I’m not aware of all your requirements so it might turn out to be a suboptimal solution.

A combination of :counters and :persistent_term can work but it could be tedious to code around.

Finally, telemetry actually sounds pretty appropriate for your use case but I’m not sure how could that help with only printing a warning once.

In case anyone stumbles across this question in their own question, the following is suitable for me needs:

  defmacro warn_once(key, message, level \\ :warn) do
    caller = __CALLER__.module

    quote do
      require Logger

      if :persistent_term.get({unquote(caller), unquote(key)}, true) do
        Logger.unquote(level)(unquote(message))
        :persistent_term.put({unquote(caller), unquote(key)}, nil)
      end
    end
  end

I wrap this at the calling site with a macro to make the inclusion of this generated code dependent on configuration, and whether :persistent_term exists.

3 Likes

Good solution. :+1:

Changing persistent_term value is, I hear, expensive, but since it’s done very rarely in this scenario, the added peace of mind is very worth it.

2 Likes