エンジニアのソフトウェア的愛情

または私は如何にして心配するのを止めてプログラムを・愛する・ようになったか

OTP標準装備のハンドラの利用手段がElixirのLoggerに標準装備されたので、その覚書

Elixir

Elixir Logger に Erlang/OTP logger がやってきた

およそ半年前、1 月にこのような記事を書きました。

blog.emattsan.org

ログローテーションなどを装備したファイル出力を可能にするハンドラが OTP 21.0 で装備されていて、それを Elixir から利用しようという話でした。

先ごろ公開された Elixir 1.15.0 では、これらの仕組みが Elixir の Logger に統合され、もっと自然な形で利用できるようになりました。

Integration with Erlang/OTP logger

This release provides additional features such as global logger metadata and file logging (with rotation and compaction) out-of-the-box!

This release also soft-deprecates Elixir's Logger Backends in favor of Erlang's Logger handlers. Elixir will automatically convert your :console backend configuration into the new configuration. Previously, you would set:

https://github.com/elixir-lang/elixir/blob/v1.15/CHANGELOG.md#integration-with-erlangotp-logger

今回はその覚書です。

使ってみる

設定

実のところ。 ブログの記事にするまでもなく、使い方は Logger のドキュメントの Configuration に例として書かれています。

設定ファイルに次のような設定を書くだけで、ログのファイル出力とローテーションが手に入ります。

import Config

config :logger, :default_handler,
  config: [
    file: ~c"system.log",
    filesync_repeat_interval: 5000,
    file_check: 5000,
    max_no_bytes: 10_000_000,
    max_no_files: 5,
    compress_on_rotate: true
  ]

https://hexdocs.pm/logger/Logger.html#module-configuration

気をつけるところとしては、これは OTP の設定を記述しているので、ファイル名は文字リストで指定する必要があるという点です。

Elixir の文字列（バイナリ）を指定してしまうと次のようなメッセージが表示され、どこにもログが出力されない状態になるのでご注意を。

Could not attach default Logger handler: {:handler_not_added, {:invalid_config, :logger_std_h, %{file: "/Users/matsumotoeiji/Documents/my_app/log/system.log"}}}

個々の設定の説明は OTP のドキュメントに記載されているので参照してください。

www.erlang.org

今回は、ログローテーションを確認したいのでファイルサイズの上限を小さくし、log/ ディレクトリに出力されるようにファイルパスを変更して利用することにします。

config :logger, :default_handler,
  config: [
    file: ~c"log/system.log",
    ...
    max_no_bytes: 1_000,
    ...
  ]

実行

単純なログを出力するサンプルを書いて、実行してみます。

defmodule MyApp do
  require Logger

  def hello do
    1..1_000_000
    |> Enum.each(fn n -> Logger.info("Hello #{n}")
    end)
  end
end

my_app $ iex -S mix
Erlang/OTP 25 [erts-13.2.2.1] [source] [64-bit] [smp:10:10] [ds:10:10:10] [async-threads:1] [jit] [dtrace]

Interactive Elixir (1.15.0) - press Ctrl+C to exit (type h() ENTER for help)
iex(1)> MyApp.hello()
:ok

log/ ディレクトリを確認すると、記録途中の log/system.log のほかに 5 つの圧縮ファイルを確認できます。

-rw-r--r--  1 matsumotoeiji  staff  817  6 24 08:35 log/system.log
-rw-r--r--  1 matsumotoeiji  staff  139  6 24 08:35 log/system.log.0.gz
-rw-r--r--  1 matsumotoeiji  staff  144  6 24 08:35 log/system.log.1.gz
-rw-r--r--  1 matsumotoeiji  staff  128  6 24 08:35 log/system.log.2.gz
-rw-r--r--  1 matsumotoeiji  staff  148  6 24 08:35 log/system.log.3.gz
-rw-r--r--  1 matsumotoeiji  staff  139  6 24 08:35 log/system.log.4.gz

ファイルが 5 つなのは設定で max_no_files: 5 を、圧縮されているのは ompress_on_rotate: true を指定したためです。 また事前にディレクトリを作成しなくても、ログファイル作成時に自動的にディレクトリを作成してくれているのがわかります。

ちなみに。 最初のログファイルは、ハンドラが Logger に割り当てられたタイミングで作成されるようで、今回のように設定ファイルに記述したばあいは起動時に作成されていました。

my_app $ rm -rf log
my_app $ iex -S mix
Erlang/OTP 25 [erts-13.2.2.1] [source] [64-bit] [smp:10:10] [ds:10:10:10] [async-threads:1] [jit] [dtrace]

Interactive Elixir (1.15.0) - press Ctrl+C to exit (type h() ENTER for help)
iex(1)> File.ls("log")
{:ok, ["system.log"]}

装飾を解く

ここで log/system.log をエディタなどで開いてみると ANSI エスケープシーケンス が含まれているのがわかります（表現の都合で、"エスケープコード + [" を "^[[" と書いています）。

^[[22m
08:46:33.127 [info] Hello 794990
^[[0m^[[22m
08:46:33.127 [info] Hello 794991
...

エスケープシーケンスによる着色はコンソールで見る分には便利ですが、ファイルで扱うときは邪魔なことが多いのでこれをオフにします。

出力形式の指定も設定ファイルでおこないますが、今回ここにも変更が入り handler の設定と formatter の設定が分離されました。

ドキュメントにありますが、従来の次のような記述は、

config :logger, :console,
  level: :error,
  format: "$time $message $metadata"

このように解釈されるようになっています。

config :logger, :default_handler,
  level: :error

config :logger, :default_formatter,
  format: "$time $message $metadata"

https://hexdocs.pm/logger/Logger.html#module-backends-and-backwards-compatibility

今後は :default_handler, :default_formatter を使った記述が求められるようです。

さて。 着色をオフにするために、 colors: [enabled: false] を指定します。

import Config

config :logger, :default_handler,
  config: [
    ...
  ]

config :logger, :default_formatter,
  colors: [enabled: false]

設定の詳細は Logger.Formatter のドキュメント を参照してください。

再度ログを出力してみると、こんどはエスケープシーケンスが出力されていないことが確認できると思います。

09:07:22.784 [info] Hello 813833

09:07:22.784 [info] Hello 813834

...

いつか読むはずっと読まない：自然言語の中の構造

自然言語にも当然のように構造があるわけですが、意味でなく形式でことが多々あるというのが興味深い話。 例えば「特定の語が現れたら後続のどこかに特定の助詞が現れないと文章として違和感を感じる」とのことで、たしかに意味はわかるのだけれど読んでいて座りのよくない文章がいくつも例示されています。

よい文章が書けるかはともかく、こういった点を気をつけて、多少なりとも読みやすい文章が書けたらよいな、と思ったり思わなかったり。

ふだん使いの言語学: 「ことばの基礎力」を鍛えるヒント (新潮選書)

ふだん使いの言語学: 「ことばの基礎力」を鍛えるヒント (新潮選書)

Amazon

ちなみに。 先に「白と黒のとびら: オートマトンと形式言語をめぐる冒険」などを読んでいたので気づかなかったのですが、著者はもともと言語学を学びそこから情報科学の分野に移られたとのこと。 そのことにご本人は思うところがあるようですが、一読者としてはふだん触れる機会の少ない分野とをつないでくれる著者のような存在は、とてもありがたく感じます。