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

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

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

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

...

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

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

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

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

Elixirで書く極々シンプルなWebサーバの覚え書き

ちょっとした Web サーバが欲しくなったときに使えるコードの覚え書きです。

基本の形は Plug のドキュメントに書かれている通りです。

hexdocs.pm

任意の Content-Type のレスポンスを返せるように :mimerl を使って Content-Type を設定するようにしたのが唯一の工夫です。

hex.pm

Mix.install([:plug, :plug_cowboy, :mimerl])

defmodule MyPlug do
  import Plug.Conn

  def init(options) do
    # initialize options
    options
  end

  def call(conn, _opts) do
    path = Path.expand("./" <> conn.request_path, File.cwd!())

    context_type = :mimerl.filename(path)

    conn
    |> put_resp_content_type(context_type)
    |> send_resp(200, File.read!(path))
  end
end

webserver = {Plug.Cowboy, plug: MyPlug, scheme: :http, options: [port: 4000]}
{:ok, _} = Supervisor.start_link([webserver], strategy: :one_for_one)

Process.sleep(:infinity)

あとはファイルに保存して Elixir で実行するだけです。

# 上記のコードを web_server.exs というファイル名で保存し、elixir コマンドで実行する
$ elixir web_server.exs

Phoenix Framework を利用したことがあれば Plug のしくみは馴染みのあるものなので、手を加えるのも比較的容易かと思います。

Phoenix LiveView で無限スクロール

背景という名の釈明

先日から仕事で無限スクロールの処理の修正に関わっていて、「これこそ Phoenix LiveView を使えば簡単なのにな」などと感じたので、LiveView の無限スクロールの記事を書くことにしました。

記事にするコードを書き終え、あとは文章を書くだけ、というところで Elixir Forum を開いたら、Phoenix LiveView で書く無限スクロールの話題が Fly.io の「The Phoenix Files」に掲載されているのを見つけました。

fly.io

正しくは。 無限スクロールを含むチャットアプリケーションの話題なので、わたしが書こうとしていたものよりずっと充実した内容になっています。

さてどうしたものか、と三日三晩ほど思案しましたが、自分のための備忘録ぐらいにはなるだろうと観念して記事にすることにしました。 そもそもこのブログ記事は、大体は自分のための備忘録ですし。

そんなわけで無限スクロールです。

アイテムを一覧表示する、まずは手動で

まずは前段階として、アイテムを一覧表示し、続きは手動で読み込む LiveView を準備します。

lib/my_app_web/live/item_live.ex

MyApp.Item.list_items/2 でアイテムの一覧を取得し表示する単純な LiveView です。 ただし一覧の取得に時間がかかることを前提として、一覧取得の処理を Task.async/1 で実行して、実行中は「Loading...」のメッセージを表示するようにしました。

defmodule MyAppWeb.ItemLive do
  use MyAppWeb, :live_view

  alias MyApp.Item

  @impl true
  def render(assigns) do
    ~H"""
    <.header>Items</.header>

    <div id="items" class="border-t border-b divide-y" phx-update="stream">
      <div :for={{dom_id, item} <- @streams.items} id={dom_id} class="py-4">
        <%= item.content %>
      </div>
    </div>

    <div class="flex justify-center mt-4">
      <.button :if={!@loading} type="button" phx-click="load">load</.button>
      <span :if={@loading}>Loading...</span>
    </div>
    """
  end

  @impl true
  def mount(_params, _session, socket) do
    task =
      if connected?(socket) do
        start_loading_task(0)
      else
        nil
      end

    {
      :ok,
      socket
      |> stream(:items, [])
      |> assign(
        next_page: 1,
        loading: true, # ページを開いたときに読み込みを開始するので最初を true にしています
        task: task
      )
    }
  end

  @impl true
  def handle_event("load", _params, socket) do
    if socket.assigns.loading do
      # 読み込み中に load イベントを受け取ったばあいは何もしないようにします
      {:noreply, socket}
    else
      page = socket.assigns.next_page

      task = start_loading_task(page)

      {:noreply, assign(socket, next_page: page + 1, loading: true, task: task)}
    end
  end

  # タスクの結果を受け取りストリームに追加します
  @impl true
  def handle_info({ref, items}, socket) when socket.assigns.task.ref == ref do
    socket =
      items
      |> Enum.reduce(socket, &stream_insert(&2, :items, &1))
      |> assign(loading: false, task: nil)

    {:noreply, socket}
  end

  # `DOWN` などの、タスクの結果以外のメッセージをハンドルします
  def handle_info(_, socket) do
    {:noreply, socket}
  end

  defp start_loading_task(page) do
    Task.async(fn ->
      Item.list_items(page * 10, 10)
    end)
  end
end

lib/my_app/item.ex

データを取得するモジュールと関数です。 MyApp.Item.list_items/2 は、ちゃんとデータベースのインタフェースとして実装するのもよいのですが、簡単のため今回も擬似的なふるまいをするコードにしています。

defmodule MyApp.Item do
  defstruct [:id, :content]

  def new(id, content) do
    %__MODULE__{id: id, content: content}
  end

  def list_items(offset, size) do
    offset..(offset + size - 1)
    |> Enum.map(fn i ->
      Process.sleep(100) # 1 アイテムあたり取得に 100ms かかる状況を擬似的に表現
      new(i, "Item-#{i}")
    end)
  end
end

lib/my_app_web/router.ex

最後にルーティングを追加します。

     pipe_through :browser
 
     get "/", PageController, :home
+    live "/items", ItemLive
   end
 
   # Other scopes may use custom stacks.

実行

サーバを起動して、 http://localhost:4000/items にアクセスします。 次のような表示になると思います。

mix phx.server

「Load」ボタンを押すと表示が「Loading...」というメッセージに替わり、およそ1秒後にアイテムが10件追加で表示されます。

ここで、ボタンを押す代わりに、ボタンの位置がページ上に表示されるころのタイミングで自動的に読み込むようにすれば、無限スクロールを実現できるはずです。

アイテムを一覧表示する、今度は自動で

assets/js/app.js

ここで非常に残念で悲しいお知らせです。 「ボタンの位置がページ上に表示されるころのタイミングで自動的に読み込むように」するためには、今はまだ JavaScript でフックを記述しなければなりません。

残念でなりませんが、LiveView のおかげで記述しないければならない JavaScript の量を最小限にできるので、それで気を取り直して先に進ことにします。

今回、ある特定の要素がページ上に表示されたら読み込みを開始することにし、そのためのイベントの生成には「交差オブザーバー API」を利用します。

developer.mozilla.org

まず assets/js/app.js に次のコードを追加します。

const Hooks = {}
Hooks.AutoLoad = {
  mounted() {
    this.intersectionObserver = new IntersectionObserver((entries) => {
      if (entries[0].isIntersecting) {
        this.pushEvent('load')
      }
    })
    this.intersectionObserver.observe(this.el)
  },

  disconnected() {
    this.intersectionObserver.unobserve(this.el)
  }
}

次に既存のコードを修正して LiveSocket ソケットのオブジェクトを生成するときのオプションに、上で書いたフックを設定します。

 import topbar from "../vendor/topbar"
 
 let csrfToken = document.querySelector("meta[name='csrf-token']").getAttribute("content")
-let liveSocket = new LiveSocket("/live", Socket, {params: {_csrf_token: csrfToken}})
+let liveSocket = new LiveSocket("/live", Socket, {params: {_csrf_token: csrfToken}, hooks: Hooks})
 
 // Show progress bar on live navigation and form submits
 topbar.config({barColors: {0: "#29d"}, shadowColor: "rgba(0, 0, 0, .3)"})

これにより LiveView で AutoLoad のフックを設定した要素が画面上に現れると load イベントが発生するようになりました。

lib/my_app_web/live/item_live.ex

最後に LiveView を修正します。

まず、ボタンとメッセージを格納している divphx-hook="AutoLoad" を追加します。 フックを設定する要素は ID も設定されている必要があります。 今回はフックのために設定する以外では ID を利用していませんので、ここでは適当に "auto-load" という値を設定しています。

そして、イベントを発生させるボタンは不要になるので、単純なメッセージ表示に変更します。

       </div>
     </div>
 
-    <div class="flex justify-center mt-4">
+    <div id="auto-load" class="flex justify-center mt-4" phx-hook="AutoLoad">
-      <.button :if={!@loading} type="button" phx-click="load">load</.button>
+      <span :if={!@loading}>Load</span>
       <span :if={@loading}>Loading...</span>
     </div>
     """

これで無限スクロールへの書き換えは完了です。 ボタンをクリックしたときと同じイベントを利用しているので、読み込みの処理は変更する必要がありません。

実行

Phoenix は、開発環境であればコードの変更時のリロードが機能しているので、サーバを起動したまま上の2つのコードを変更したのでしたら、すでに表示が切り替わっていると思います。

一覧表示をスクロールして「Load」のメッセージが表示されると、すぐに「Loading...」に切り替わり、読み込みが始まることが確認できます。

実は弱点(欠点)が一つ

すでに気がつかれている方もいらっしゃると思いますが。

この実装では、一覧表示の下にあるメッセージがスクロールして現れるのではなく、最初からページ中に表示されているばあいは読み込みが発生しません。 最初に一覧するアイテムの数をページサイズに合わせて調節できるとよいのですが、書かなければならない JavaScript のコードが増えそうなので、今回は考えないことにしました。

JavaScript のコードを駆逐しつつページサイズに合わせた読み込みをする方法は、宿題とさせてください。

いつか読むはずっと読まない:単弓類、雌伏のとき

「かはく」こと国立科学博物館恐竜博2023 が始まりました。 かはくにはもう3年くらい足を運べていないので、この機に休暇をとって丸一日堪能してこようかと思います。

Phoenix 1.7 とともに LiveView Streams がやってきた

Elixir の Web フレームワークである Phoenix Framework に、待望の 1.7 がやってきました。

phoenixframework.org

やはり今回のバージョンの最大のポイントは、Controller を用いた静的な View と LiveView のテンプレートが、コンポーネントという形で統合されたところだと思います。 これで同じ部品を Controller でも LiveView でも利用できるようになりました。

これについては、いろいろな人がいろいろな記事を書いてくださると思うので、わたしは別のポイントに注目したいと思います。

リリース記事のタイトルにもある「LiveView Streams」です。

これまでの LiveView は要素の削除が苦手だった

苦手というよりも、フレームワークとして専用の機能が提供されていなかった、が正確かもしれません。 フレームワークが持つ機能を組み合わせ、たりない部分をコードで補うことで実現しなければなりませんでした。

このことについては 2020年12月に記事にも書いています。 実に2年以上前。

blog.emattsan.org

コレクションを扱う

上記のような削除の問題は、ある集まり、コレクションを扱うときに重大になってきます。 データベースを扱うケースは、まさにそのようなケースです。 Web アプリケーションのフレームワークとして「ちょっと遅れをとっている」と、個人的に感じていた部分でした。

それも、今回のバージョンアップで、それも解消されたのです。

内部的には、コレクションを抱え込むモジュールが定義され、挿入や削除の操作が標準装備されました。 フロントエンド側にも対応する操作が実装されているため、最小限のデータのやり取りで、コレクションの要素の挿入や一部の更新や削除ができるようになっています。

さっそくその恩恵を、簡単なコードで見てゆきます。

サンプルアプリケーション MyAPP

まずは mix phx.new コマンドを最新の 1.7 に更新して、サンプルのプロジェクトを作成してください。

$ mix archive.install hex phx_new
$ mix phx.new my_app
$ cd my_app

データを扱うモジュール

本格的にデータベースを利用してもよいのですが、簡単に済ませたいのと、データベースなどに影響されない本質だけを見てゆきたいので、データを扱うモジュールを一から書いてゆきます。

ここで MyApp.Items.Item はデータを格納する構造体、 MyApp.Items はデータを扱うモジュールです。 MyApp.Items.Item のリストを LiveView Stream のコレクションとするわけですが、コレクションの要素になるデータには :id という名前のキーが必要になるようです(要素自体に ID を持たせずに済ませる方法もありますが今回は省略)。

また LiveView Streams の効果がわかりやすいように、 MyApp.Items を使ったデータの更新は非同期で、結果はメッセージで受け取るようにしました。 結果を受け取りたいプロセスは、MyApp.Items.subscribe_items/0 で購読登録をし、更新時にブロードキャストされるメッセージを処理するようにします。

defmodule MyApp.Items.Item do
  defstruct [:id, :name]
end
defmodule MyApp.Items do
  use GenServer

  alias MyApp.Items.Item

  @name __MODULE__

  def start_link(opts) do
    GenServer.start_link(__MODULE__, opts, name: @name)
  end

  def subscribe_items do
    Phoenix.PubSub.subscribe(MyApp.PubSub, "items")
  end

  def list_items do
    GenServer.call(@name, :list_items)
  end

  def create_item do
    GenServer.cast(@name, :create_item)
  end

  def delete_item(id) when is_binary(id) do
    delete_item(String.to_integer(id))
  end

  def delete_item(id) do
    GenServer.cast(@name, {:delete_item, id})
  end

  def init(opts) do
    size = opts[:size] || 10

    items =
      1..size
      |> Enum.map(fn id ->
        %Item{id: id, name: "item-#{id}"}
      end)

    {:ok, %{items: items, next_id: size + 1}}
  end

  def handle_call(:list_items, _from, %{items: items} = state) do
    {:reply, items, state}
  end

  def handle_cast(:create_item, %{items: items, next_id: next_id} = state) do
    created_item = %Item{id: next_id, name: "item-#{next_id}"}

    Phoenix.PubSub.broadcast(MyApp.PubSub, "items", {:item_created, created_item})

    {:noreply, %{state | items: items ++ [created_item], next_id: next_id + 1}}
  end

  def handle_cast({:delete_item, id}, %{items: items} = state) do
    case Enum.split_with(items, &(&1.id == id)) do
      {[deleted_item], rest} ->
        Phoenix.PubSub.broadcast(MyApp.PubSub, "items", {:item_deleted, deleted_item})
        {:noreply, put_in(state.items, rest)}

      _ ->
        {:noreply, state}
    end
  end
end

最後に、アプリケーションの起動時にプロセスを起動するため MyApp.Application の children に MyApp.Items を追加します。

defmodule MyApp.Application do
  @moduledoc false

  use Application

  @impl true
  def start(_type, _args) do
    children = [
      MyApp.Items, # 追加
      # ...
    ]

    # ...
  end
end

LiveView 本体

次にデータを表示する LiveView のモジュールを追加します。 コレクションの要素を一覧するだけのシンプルなものです。

最上部に表示されている「create」ボタンで要素を追加し、各要素欄にある「delete」ボタンでその要素を削除します。 データのところで説明したように処理を非同期にしているので、ボタンを押した時の処理は MyApp.Items.Item の関数を呼び出すだけで、表示の更新はブロードキャストされたメッセージを受け取った時に行うようにしています。

ここでポイントは 4 つ。

  1. コレクションの割り当てに Phoenix.IiveView.stream/4 を使う
  2. 要素の構築は :for={{dom_id, item} <- @streams.items} id={dom_id} のように、@streams.items から ID とデータのペアを取り出し、ID を設定する
  3. 要素の追加に Phoenix.IiveView.stream_insert/4 を使う
  4. 要素の削除に Phoenix.IiveView.stream_delete/3 を使う

ちなみに、要素の更新は Phoenix.IiveView.stream_insert/4 で行います。 ID が同じ要素があるばあいは更新し、ないばあいは挿入するという動きをします。 そのために ID の指定が必須になっています。

2年あまり前に苦戦した要素の削除が、わずか一行ですんでしまいました。 またコレクションの更新を非同期の PubSub で実現したので、すべての LiveView で同時に要素の追加や削除が行われます。

defmodule MyAppWeb.ItemLive do
  use MyAppWeb, :live_view

  alias MyApp.Items
  alias MyApp.Items.Item

  def mount(_params, _session, socket) do
    items =
      if connected?(socket) do
        Items.subscribe_items()
        Items.list_items()
      else
        []
      end

    socket = stream(socket, :items, items)

    {:ok, socket}
  end

  def render(assigns) do
    ~H"""
    <h1 class="text-4xl font-bold mb-2">Items</h1>
    <div class="my-2"><.button phx-click="create-item">create</.button></div>
    <div class="border rounded-lg grid grid-cols-1 divide-y">
      <div :for={{dom_id, item} <- @streams.items} id={dom_id} class="h-12 p-2 flex items-center">
        <span class="flex-1"><%= item.name %></span>
        <.button phx-click="delete-item" phx-value-id={item.id}>delete</.button>
      </div>
    </div>
    """
  end

  def handle_event("create-item", _params, socket) do
    Items.create_item()

    {:noreply, socket}
  end

  def handle_event("delete-item", %{"id" => id}, socket) do
    Items.delete_item(id)

    {:noreply, socket}
  end

  def handle_info({:item_created, created_item}, socket) do
    {:noreply, stream_insert(socket, :items, created_item)}
  end

  def handle_info({:item_deleted, deleted_item}, socket) do
    {:noreply, stream_delete(socket, :items, deleted_item)}
  end
end

ルーティング

最後にルーティングの追加です。

defmodule MyAppWeb.Router do
  use MyAppWeb, :router

  # ...

  scope "/", MyAppWeb do
    pipe_through :browser

    # ...

    live "/items", ItemLive # 追加
  end

  # ...
end

実行

mix phx.server コマンドでアプリケーションを起動し、ブラウザで http://localhost:4000/items を開くと、次のような一覧が表示されると思います。 「create」ボタンを押すと要素が一つ追加され、「delete」ボタンを押すとその要素が削除されます。 ブラウザの複数のウィンドウでこのページを開いて追加したり削除したりすると、連動するのが見て取れると思います。

動作としては「ただそれだけ」のことなのですが、ただそれだけのことを、ただこれでだけで実現できるインパクトは決して小さくありません。

LiveView Streams にかぎらず、今回の 1.7 に搭載された機能は Phoenix をもう一段高いレベルに押し上げた感じが、個人的にはしています。

余談

このサンプルコードを書き上げたあと、Elixir Forum の Phoenix 1.7 のリリースを告げるスレッドの中に、次の投稿を見つけて「やはり」と思ったのでした。

josevalim
The win for streams will come when pushing updates to LV via PubSub. It is not in the generated code but streams get us closer to that and adding the remaining PubSub bits should be easy.

elixirforum.com

ElixirのログをOTP標準装備のハンドラでファイルに出力する覚え書き

数年前に、Elixir の Logger モジュールのカスタムバックエンドを書く、という記事を書きました。

blog.emattsan.org

ごく最近になって。 Elixir Forum で Logger の設定の記事を読み、OTP が標準で用意しているハンドラを使えば、バックエンドを書かなくてもログをファイルに出力できると知りました。 調べてみると、ハンドラは OTP 21.0 で追加された模様。

奇しくも OTP 21.0 のリリース日は、先の記事の公開日と同じ 2018/06/19 だったことに何かの縁を感じたり感じなかったり。

いまだ全貌を掴みきれていないのですが、ログをファイルに出力する最低限の設定を確認したので、忘れないうちに記録しておきます。

道具立て

logger_std_h モジュール

ハンドラには Erlang のドキュメントの次のページで紹介されている logger_std_h モジュールを利用します。

www.erlang.org

設定項目がいくつかあるのですが、ここでは出力先のファイル名を指定する file という項目のみ利用します。

ハンドラを追加する方法

Erlanglogger モジュールの add_handlers/1 関数を利用してハンドラを追加登録します。

www.erlang.org

ドキュメントに "Reads the application configuration parameter logger and calls add_handlers/1 with its contents." とあるように、設定は config ファイルに記述することになります。

設定の記述法

設定はどのように記述するのか。 logger:add_handlers/1 関数をどこで呼び出すのか。 これらは、Elixir の Logger モジュールのドキュメントに記述があります。

hexdocs.pm

Erlang/OTP handlers must be listed under your own application:

config :my_app, :logger, [
  {:handler, :name_of_the_handler, ACustomHandler, configuration = %{}}
]

And then, explicitly attached in your Application.start/2 callback:

:logger.add_handlers(:my_app)

見ての通り、ドキュメントの記述は Application モジュールを利用することを前提としています。 logger:add_handlers/1 関数を適当なタイミングで呼び出せれば Application モジュールを使わなくてもよいようですが、ここではドキュメントにならって Application ありで書いてゆきます。

実際にログをファイルに出力してみる

プロジェクトを用意する

Application モジュールを利用する雛形を生成するため、--sup オプション付きで mix new コマンドを実行します。

$ mix new my_app --sup
$ cd my_app

config/config.exs ファイルを書く

logger_std_h モジュールを利用する設定を config/config.exs に記述します。

コード中 config: %{...} で記述しているオプションは、Erlang のドキュメントにあったオプションの内容です。 Erlang のオプションであるため、ファイル名は Elixir の文字列(バイナリ)ではなく、Erlang の文字列(文字リスト)で指定する必要があります。

import Config

config :my_app, :logger, [
  {
    :handler,
    :my_log,       # ハンドラを識別するための ID
    :logger_std_h, # 利用するハンドラ
    %{
      config: %{
        # 注意! ファイル名は、String (binary) でなく charlist で指定する
        file: 'log/my_log.log'
      }
    }
  }
]

lib/my_app/application.ex にハンドラを追加するコードを書く

logger:add_handlers/1 関数を呼び出すコードを lib/my_app/application.ex に追加します。

defmodule MyApp.Application do
  @moduledoc false

  use Application

  @impl true
  def start(_type, _args) do
    :logger.add_handlers(:my_app) # この行を追加

    children = [
    ]

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

ここまで記述できたら IEx を起動します。

$ iex -S mix

ハンドラが追加されていることを確認する

登録されているハンドラは logger:get_handler_ids/0 関数で確認することができます。

iex> :logger.get_handler_ids()
[:my_log, Logger]

config/config.exs に記述したハンドラの ID が表示されると思います。 そして、見ての通り、Elixir 標準の Logger も登録されていることがわかります。

この方法は、起動済みのハンドラを変更することはせず、あくまで追加で登録するためのもののようです。

ログを出力してみる

準備ができたのでログを出力して確認してみます。

iex> require Logger                       
Logger
iex> Logger.info("Hello")                 

19:28:42.693 [info] Hello
:ok

標準のハンドラも有効なので、コンソールにログが出力されました。

ファイルを確認してみます。

iex> File.read!("log/my_log.log") |> IO.puts()
2023-01-30T19:28:37.413517+09:00 info: Application: my_app. Started at: nonode@nohost.
2023-01-30T19:28:42.693326+09:00 info: Hello

:ok

ファイルには、Logger.info/1 で出力する前にアプリケーションが起動した時のログも記録されていました。

ディスク用のハンドラもある

ここでは logger_std_h モジュールを使いましたが、それとは別にディスク出力向けのハンドラ logger_disk_log_h も用意されています。

www.erlang.org

ドキュメントを見てみると、ログローテーションをはじめディスクに出力することを意識したとおぼしきオプションが並んでいます。 こちらのハンドラも折を見て試してみようと思います。

いつか読むはずっと読まない:Science と Fiction のはざま

しまった。 まだ「三体」読んでない。

LiveViewでTaskの結果はhandle_infoで受ければよいという話

LiveViewでTaskの結果はhandle_infoで受ければよいという話

ElixirWeekly の何号だったか失念してしまったのですが。

LiveView のプロセスで、非同期処理を Task.async/1 で実行したならば、Task.async/1 が終了時に送信するメッセージを受け取ればよい、というお話。

プロセスのふるまいを学んだときに、どのようなメッセージが送られるか問いことを覚えたはずなのに、文脈が変わっただけでこうも気付けなくなるものかと思い知った次第。

おさらい Task.async/1

Task.async/1 を実行すると、Task 構造体が返ります。

構造体の中のキー :ref にタスクを識別するリファレンスが格納されています。

iex(1)> Task.async(fn -> :timer.sleep(100); 123 end)
%Task{
  owner: #PID<0.109.0>,
  pid: #PID<0.111.0>,
  ref: #Reference<0.1023354925.2953576457.207757>
}

タスクが終了すると、リファレンスとタスクの最後の値のペアがメッセージとして送られてきます。

最後にタスクのプロセスが終了したことの通知 :DOWN が送られます。

iex(2)> flush
{#Reference<0.1023354925.2953576457.207757>, 123}
{:DOWN, #Reference<0.1023354925.2953576457.207757>, :process, #PID<0.111.0>,
 :normal}
:ok

これをふまえて

初期状態 stopping のときに START ボタンを押すと、starting と表示されのち1秒後に running の表示に換わるサンプルです。

Task.async/2 の戻り値に含まれるリファレンスを保存しておきます。 受信したメッセージにタスクのリファンレンスが含まれていれば、先に起動したタスクの結果のメッセージなので、処理をします。

プロセス終了時の :DOWN を含むメッセージも送られてくるので、そのメッセージにマッチする handle_info/2 を用意しておかなければなりません。 ここでは他のすべてのメッセージは無視するようにしています。

defmodule MyAppWeb.PageLive do
  use MyAppWeb, :live_view

  def mount(_params, _session, socket) do
    {:ok, assign(socket, status: "stopped", ref: nil)}
  end

  def render(assigns) do
    ~H"""
    <button phx-click="start">start</button>
    <div><%= @status %></div>
    """
  end

  # ボタンの phx-click="start" のイベントハンドラ
  def handle_event("start", _, socket) do
    task = Task.async(fn ->
      # (時間のかかる処理の代わり)
      Process.sleep(100)
      123
    end)

    {:noreply, assign(socket, status: "starting", ref: task.ref)}
  end

  # タスクの結果を受け取る
  # (socket に格納したリファレンスと受信したメッセージに含まれるリファレンスが一致をチェックする)
  def handle_info({ref, _result}, socket) when socket.assigns.ref == ref do
    {:noreply, assign(socket, status: "running")}
  end

  # :DOWN のメッセージ等を無視する
  def handle_info(_, socket) do
    {:noreply, socket}
  end
end

aws-sdkで取得できるタグを扱いやすくするための覚書

動機

AWS のリソースの多くは key-value の組みをタグとして設定できるようになっているのですが。

例えば EC2 インスタンスを取得する aws-sdk のメソッド Aws::EC2::Client#describe_instances のレスポンスは次のようになっています。

resp.reservations[0].instances[0].tags #=> Array
resp.reservations[0].instances[0].tags[0].key #=> String
resp.reservations[0].instances[0].tags[0].value #=> String

docs.aws.amazon.com

つまり辞書形式になっているわけではなく、単に key と value のペアを格納するクラスの配列にすぎません。

実装を紐解いてみると、次のような構造になっていました。

class Tag < Struct.new(:key, :value)
end

key から value を引きたい場合、たとえば次のようなコードを書くことになります。

tags = [
  Tag.new("foo", 123),
  Tag.new("bar", 456),
  Tag.new("baz", 789)
]

pp tags.find { |tag| tag.key == "foo" }&.value  # => 123
pp tags.find { |tag| tag.key == "bar" }&.value  # => 456
pp tags.find { |tag| tag.key == "baz" }&.value  # => 789
pp tags.find { |tag| tag.key == "hoge" }&.value # => nil

これがもう少しどうにかならないか、というのが今回のお題です。

クラスで包む

Tag の配列を内部に持ち、key-value アクセスを容易にするメソッドを用意するパタンです。

class Tags
  def self.[](tags)
    new(tags)
  end

  def initialize(tags)
    @tags = tags
  end

  def [](key)
    @tags.find { |tag| tag.key == key }&.value
  end
end

pp Tags[tags]["foo"]  # => 123
pp Tags[tags]["bar"]  # => 456
pp Tags[tags]["baz"]  # => 789
pp Tags[tags]["hoge"] # => nil

これは C++ のときに割と好んで利用していた方法です。

#include <algorithm>
#include <iostream>
#include <string>
#include <vector>

struct Tag {
    std::string key;
    int value;
};

class Tags {
public:
    Tags(const std::vector<Tag>& tags) : tags_(tags) {}

    int operator [] (const std::string& key) {
        auto tag = std::find_if(tags_.begin(), tags_.end(), [&](const Tag& tag) { return tag.key == key; });
        return tag->value;
    }

private:
    const std::vector<Tag>& tags_;
};

int main(int, char*[]) {
    auto tags = {
        Tag { "foo", 123 },
        Tag { "bar", 456 },
        Tag { "baz", 789 }
    };

    std::cout << Tags(tags)["foo"] << std::endl;
    std::cout << Tags(tags)["bar"] << std::endl;
    std::cout << Tags(tags)["baz"] << std::endl;
}

これは、動的にクラスのメソッドを変更できない環境ではよくある方法と思いますが、Ruby では個々のオブジェクトにも固有のメソッドを追加できることを利用して、tags オブジェクトにメソッドを追加してみようと思います。

オブジェクトを拡張する (1)

今回はメソッドを定義する Tags をモジュールとして定義し、Object#extend を利用して tags オブジェクトにメソッドを組み込んでいます。

module Tags
  def [](key)
    find { |tag| tag.key == key }&.value
  end
end

tags.extend(Tags)

pp tags["foo"]  # => 123
pp tags["bar"]  # => 456
pp tags["baz"]  # => 789
pp tags["hoge"] # => nil

ただし #[] を上書きしてしまうため Array として機能しなくなるというかなり重度な欠点を抱えます。 Array と被らない名前を選べばよい話ではあるのですが。

pp tags[0] # => nil
pp tags[1] # => nil
pp tags[2] # => nil

オブジェクトを拡張する (2)

より Ruby ならではの方法といえば、やはり BasicObject#method_missing のオーバーライド。 アクセスできるキーがメソッドとして記述できる識別子に限られるという制約がありますが、オブジェクトの属性のように扱うことができるのでとても強力です。

module Tags
  def method_missing(name)
    key = name.to_s
    find { |tag| tag.key == key }&.value
  end
end

tags.extend(Tags)

pp tags.foo  # => 123
pp tags.bar  # => 456
pp tags.baz  # => 789
pp tags.hoge # => nil