檢視原始碼 Telemetry

在本指南中，我們將展示如何在 Phoenix 應用程式中註析及報告 :telemetry 事件。

te·lem·e·try - 記錄並傳輸儀器讀數的過程。

隨著本指南的進度，我們將向您介紹 Telemetry 的核心概念，您將初始化一個報告工具來捕捉您應用程式的事件，以及我們將指導您使用 :telemetry 正確註析您自己的函式。讓我們進一步了解如何 Telemetry 在您的應用程式中運作。

概述

[:telemetry] 函式庫允許您在應用程式生命週期的各個階段發射事件。然後就可以回應這些事件，包含在內，將它們彙整成指標，並將指標資料傳送至報告目標。

Telemetry 會在 ETS 表中依名稱儲存事件，以及每個事件的處理程式。然後，當執行某個事件時，Telemetry 會查詢它的處理程式並呼叫它。

Phoenix 的 Telemetry 工具提供一個使用 Telemetry.Metrics 的督導，來定義要處理的 Telemetry 事件清單，以及如何處理這些事件，亦即如何將它們結構為某種類型的指標。此督導與 Telemetry 報告工具合作，回應指定的 Telemetry 事件，將它們彙整為適當的指標並傳送至正確的報告目標。

Telemetry 督導

自 v1.5 以後，新產生的 Phoenix 應用程式會使用 Telemetry 督導。這個模組負責管理您的 Telemetry 處理程序的生命週期。它也定義一個 metrics/0 函式，其中會傳回您為應用程式定義的 Telemetry.Metrics 清單。

預設情況下，督導也會啟用 :telemetry_poller。只要簡單加入 :telemetry_poller 作為相依套件，您就可以在指定的間隔收到與 VM 相關的事件。

如果您使用的是較舊版本的 Phoenix，請安裝 :telemetry_metrics 和 :telemetry_poller 套件

{:telemetry_metrics, "~> 1.0"},
{:telemetry_poller, "~> 1.0"}

並在 lib/my_app_web/telemetry.ex 中建立你的 Telemetry 監督器

# lib/my_app_web/telemetry.ex
defmodule MyAppWeb.Telemetry do
  use Supervisor
  import Telemetry.Metrics

  def start_link(arg) do
    Supervisor.start_link(__MODULE__, arg, name: __MODULE__)
  end

  def init(_arg) do
    children = [
      {:telemetry_poller, measurements: periodic_measurements(), period: 10_000}
      # Add reporters as children of your supervision tree.
      # {Telemetry.Metrics.ConsoleReporter, metrics: metrics()}
    ]

    Supervisor.init(children, strategy: :one_for_one)
  end

  def metrics do
    [
      # Phoenix Metrics
      summary("phoenix.endpoint.stop.duration",
        unit: {:native, :millisecond}
      ),
      summary("phoenix.router_dispatch.stop.duration",
        tags: [:route],
        unit: {:native, :millisecond}
      ),
      # VM Metrics
      summary("vm.memory.total", unit: {:byte, :kilobyte}),
      summary("vm.total_run_queue_lengths.total"),
      summary("vm.total_run_queue_lengths.cpu"),
      summary("vm.total_run_queue_lengths.io")
    ]
  end

  defp periodic_measurements do
    [
      # A module, function and arguments to be invoked periodically.
      # This function must call :telemetry.execute/3 and a metric must be added above.
      # {MyApp, :count_users, []}
    ]
  end
end

請務必用你的實際應用程式名稱取代 MyApp。

然後新增至你的主要應用程式的監督樹中（通常在 lib/my_app/application.ex）

children = [
  MyAppWeb.Telemetry,
  MyApp.Repo,
  MyAppWeb.Endpoint,
  ...
]

Telemetry 事件

許多 Elixir 函式庫（包括 Phoenix）已經使用 :telemetry 套件，透過在應用程式生命週期的關鍵時刻發出事件，讓使用者更深入瞭解其應用程式的行為。

Telemetry 事件包含以下內容

name - 字串（例如 "my_app.worker.stop"）或識別事件的原子陣列。
measurements - 原子鍵（例如 :duration）和數值測量值的對應表。
metadata - 可用於標記指標之關鍵字對對應表。

Phoenix 範例

以下是你端點事件的範例

[:phoenix, :endpoint, :stop] - 由 Plug.Telemetry 發出，這是你端點的預設外掛程式之一，每當傳送回應時
- 測量值：%{duration: native_time}
- 資料：%{conn: Plug.Conn.t}

這表示在每個請求後，Plug 會透過 :telemetry 發出「停止」事件，其中測量值為取得回應所花的時間

:telemetry.execute([:phoenix, :endpoint, :stop], %{duration: duration}, %{conn: conn})

Phoenix Telemetry 事件

所有 Phoenix telemetry 事件的完整清單可以在 Phoenix.Logger 中找到

指標

指標是具有特定名稱的 Telemetry 事件的彙整，提供系統行為隨著時間推移的視圖。
― Telemetry.Metrics

Telemetry.Metrics 套件提供定義指標的共通介面。它公開一組五個指標類型函式，負責將特定的 Telemetry 事件結構為特定測量值。

該套件本身不執行任何測量值彙整。相反地，它提供一個報告器，其中包含 Telemetry 事件作為測量值定義，而報告器使用該定義來執行彙整並報告它們。

我們將在下一章節中討論報告器。

來看看一些範例。

使用 Telemetry.Metrics，你可以定義一個計數器指標，用以計算完成的 HTTP 請求數目

Telemetry.Metrics.counter("phoenix.endpoint.stop.duration")

或您可以使用 distribution metric 來檢視在特定時間區間中完成多少 запросы

Telemetry.Metrics.distribution("phoenix.endpoint.stop.duration")

這樣回顧 HTTP запросы 的能力很強大——而這只是 Phoenix 框架所發出的眾多遥测事件之一！稍後在本指南的〈Phoenix Metrics〉章節中，我們將討論更多這些事件，以及從 Phoenix/Plug 事件中提取有價值資料的特定範例。

從 Phoenix 發出的所有 :telemetry 事件的完整清單，連同它們的量測標準和 metadata，可在 Phoenix.Logger 模組文件的「Instrumentation」章節中取得。

Ecto 例子

和 Phoenix 一樣，Ecto 採用內建的 Telemetry 事件。這表示您可以使用同樣的工具回顧您的 web 和資料庫層。

以下是 Ecto 在 Ecto 資料庫啟動時執行的 Telemetry 事件範例

[:ecto, :repo, :init] - 由 Ecto.Repo 分派
- 量測標準：%{system_time: native_time}
- metadata：%{repo: Ecto.Repo, opts: Keyword.t()}

這表示每當 Ecto.Repo 啟動時，它會透過 :telemetry 發出一個事件，其中含有啟動時間的量測標準。

:telemetry.execute([:ecto, :repo, :init], %{system_time: System.system_time()}, %{repo: repo, opts: opts})

Ecto adapter 會執行其他 Telemetry 事件。

其中一個 adapter 特定事件是 [:my_app, :repo, :query] 事件。例如，如果您想要繪製查詢執行時間的圖表，您可以使用 Telemetry.Metrics.summary/2 函式指示您的 reporter 計算 [:my_app, :repo, :query] 事件的統計資料，例如最大值、平均值、百分比等。

Telemetry.Metrics.summary("my_app.repo.query.query_time",
  unit: {:native, :millisecond}
)

或者您可以使用 Telemetry.Metrics.distribution/2 函式為另一個 adapter 特定事件定義直方圖：[:my_app, :repo, :query, :queue_time]，如此一來便能視覺化表示查詢排隊等待的時間長度

Telemetry.Metrics.distribution("my_app.repo.query.queue_time",
  unit: {:native, :millisecond}
)

您可以在 Ecto.Repo 模組文件的「Telemetry Events」章節中進一步了解 Ecto Telemetry。

到目前為止，我們已經了解一些 Phoenix 應用程式的常見 Telemetry 事件，以及它們的各種量測標準和 metadata。由於所有這些資料都等待使用，因此我們來談談記者。

記者

記者使用 Telemetry.Metrics 所提供的常見介面訂閱 Telemetry 事件。然後他們將量測標準（資料）彙整到指標中，以便提供應用程式的有意義資訊。

例如，假設將下列 Telemetry.Metrics.summary/2 呼叫新增至 Telemetry 監督器的 metrics/0 函式

summary("phoenix.endpoint.stop.duration",
  unit: {:native, :millisecond}
)

那麼，報告器會附加一個 "phoenix.endpoint.stop.duration" 事件的監聽器，並會計算具備所提供事件中繼資料的摘要指標，並在該指標上回報適當的來源，以回應此事件。

Phoenix.LiveDashboard

對於有興趣對其 Telemetry 指標進行即時視覺化的開發人員，您可能會想要安裝 LiveDashboard。LiveDashboard 作用為 Telemetry.Metrics 報告器，將資料呈現在儀表板上的精美即時圖表上。

Telemetry.Metrics.ConsoleReporter

Telemetry.Metrics 附有一個 ConsoleReporter，可用於將事件和指標印製至終端機。您可以使用此報告器來實驗本指南中討論的指標。

取消註解或將下列內容新增至您 Telemetry 監督樹中的這個子項清單（通常在 lib/my_app_web/telemetry.ex 中）

{Telemetry.Metrics.ConsoleReporter, metrics: metrics()}

有許多報告器可供使用，可針對 StatsD、Prometheus 等服務。您可以透過在 hex.pm 上搜尋「telemetry_metrics」來尋找這些報告器。

Phoenix 指標

前面我們看著由 Plug.Telemetry 發出的「停止」事件，並使用它來統計 HTTP 要求的數量。實際上，只看到要求的總數僅有部份幫助。如果你想定看到每條路由或每條路由和方法的要求數，會怎樣？

讓我們來看看 HTTP 要求生命週期中發出的另一個事件，這次是來自 Phoenix.Router

[:phoenix, :router_dispatch, :stop] - 由 Phoenix.Router 在成功派送至符合的路線後派送
- 測量值：%{duration: native_time}
- 中繼資料：%{conn: Plug.Conn.t, route: binary, plug: module, plug_opts: term, path_params: map, pipe_through: [atom]}

讓我們先依據路由將這些事件組合。將下列內容（如果尚未存在）新增至 Telemetry 監督器的 metrics/0 函式（通常在 lib/my_app_web/telemetry.ex 中）

# lib/my_app_web/telemetry.ex
def metrics do
  [
    ...metrics...
    summary("phoenix.router_dispatch.stop.duration",
      tags: [:route],
      unit: {:native, :millisecond}
    )
  ]
end

重新啟動您的伺服器，然後對一個或兩個網頁提出要求。在您的終端機中，您會看到 ConsoleReporter 印出它收到的 Telemetry 事件的記錄，這些是根據您提供的指標定義衍生的。

每個請求的日誌記錄行都會包含該請求的特定路線。這是因為為摘要量測值指定 :tags 選項，這符合我們的首要需求；我們可以使用 :tags 根據路線對量測值進行分組。請注意，報表員勢必會根據所使用的基礎服務對標籤進行不同的處理。

仔细查看 Router 「停止」事件，您可以看到表示請求的 Plug.Conn 結構出現在元資料中，但您要如何存取 conn 中的屬性？

幸運的是，Telemetry.Metrics 提供以下選項來協助您對事件進行分類

:tags - 分組的元資料金鑰清單；
:tag_values - 將元資料轉換為所需形狀的函數；請注意，此函數會為每個事件呼叫，因此如果事件頻率很高，則讓它保持快速的執行速度非常重要。

在 Telemetry.Metrics 模組的文件中了解所有可用的量測值選項。

讓我們找出如何從包含 conn 的事件元資料中擷取更多標籤。

從 Plug.Conn 擷取標籤值

讓我們為路由事件新增另一個量測值，這次透過路線和方法進行分組

summary("phoenix.router_dispatch.stop.duration",
  tags: [:method, :route],
  tag_values: &get_and_put_http_method/1,
  unit: {:native, :millisecond}
)

我們在此處引入了 :tag_values 選項，因為我們需要對事件元資料執行轉換，才能取得我們需要的數值。

將以下私人函數新增到您的 Telemetry 模組，以從 Plug.Conn 結構中取得 :method 值

# lib/my_app_web/telemetry.ex
defp get_and_put_http_method(%{conn: %{method: method}} = metadata) do
  Map.put(metadata, :method, method)
end

重新啟動您的伺服器，並提出一些請求。您應該會開始看到同時包含 HTTP 方法和路由標籤的記錄。

請注意，:tags 和 :tag_values 選項可套用至所有 Telemetry.Metrics 類型。

使用標籤值重新命名數值標籤

有時候，在顯示量測值時，可能需要轉換數值標籤以改善可讀性。以顯示各個 LiveView 的 mount/3 回應，依據已連線 connected? 狀態顯示其持續時間的量測值為例。

summary("phoenix.live_view.mount.stop.duration",
  unit: {:native, :millisecond},
  tags: [:view, :connected?],
  tag_values: &live_view_metric_tag_values/1
)

下列函數將 metadata.socket.view 和 metadata.socket.connected? 提昇至 metadata 上的頂層金鑰，如同我們在之前範例中所做的一樣。

# lib/my_app_web/telemetry.ex
defp live_view_metric_tag_values(metadata) do
  metadata
  |> Map.put(:view, metadata.socket.view)
  |> Map.put(:connected?, Phoenix.LiveView.connected?(metadata.socket))
end

不過，在 LiveDashboard 中呈現這些量測值時，數值標籤會輸出為 "Elixir.Phoenix.LiveDashboard.MetricsLive true"。

為了讓數值標籤更容易閱讀，我們可以更新我們的私有函式，以產生更友善的使用者名稱。我們會執行 :view 的值，並透過 inspect/1 移除 Elixir. 前綴名稱，並呼叫另一個私有函式將 connected? 布林值轉換成人們可閱讀的文字。

# lib/my_app_web/telemetry.ex
defp live_view_metric_tag_values(metadata) do
  metadata
  |> Map.put(:view, inspect(metadata.socket.view))
  |> Map.put(:connected?, get_connection_status(Phoenix.LiveView.connected?(metadata.socket)))
end

defp get_connection_status(true), do: "Connected"
defp get_connection_status(false), do: "Disconnected"

現在，數值標籤會以 "Phoenix.LiveDashboard.MetricsLive 已連線" 的形式呈現。

希望對於如何使用 :tag_values 選項，這部分有提供你一些靈感。請記住，由於這個函式會在每個事件中被呼叫，因此要保持函式的執行速度。

定期量測

你可能想要定期量測應用程式中的鍵值對。很幸運的，:telemetry_poller 套件提供自訂量測的方式，這對於定期擷取處理緒資訊或執行自訂量測很有用。

將下列內容新增至 Telemetry 監督器的 periodic_measurements/0 函式清單中，此函式是一個私有函式，用於傳回一個量測清單，並在指定的區間中執行。

# lib/my_app_web/telemetry.ex
defp periodic_measurements do
  [
    {MyApp, :measure_users, []},
    {:process_info,
      event: [:my_app, :my_server],
      name: MyApp.MyServer,
      keys: [:message_queue_len, :memory]}
  ]
end

其中 MyApp.measure_users/0 可以寫成像這樣

# lib/my_app.ex
defmodule MyApp do
  def measure_users do
    :telemetry.execute([:my_app, :users], %{total: MyApp.users_count()}, %{})
  end
end

現在，當量測已經就緒，你可以針對上述事件定義量測

# lib/my_app_web/telemetry.ex
def metrics do
  [
    ...metrics...
    # MyApp Metrics
    last_value("my_app.users.total"),
    last_value("my_app.my_server.memory", unit: :byte),
    last_value("my_app.my_server.message_queue_len")
    summary("my_app.my_server.call.stop.duration"),
    counter("my_app.my_server.call.exception")
  ]
end

你將會在自訂事件章節中實作 MyApp.MyServer。

使用 Telemetry 的函式庫

Telemetry 很快的成為 Elixir 中套件儀器化的實際標準。以下是目前發出 :telemetry 事件的函式庫清單。

鼓勵函式庫作者主動發送一個 PR，加入他們自己的事件（請按字母順序排列）

自訂事件

如果你需要應用程式中的自訂量測和儀器化，你可以利用 :telemetry 套件 (https://hexdocs.dev.org.tw/telemetry)，就像你最愛的框架和函式庫那樣。

以下是發出遙測事件的簡單 GenServer 範例。在您的應用程式中建立這個檔案於 lib/my_app/my_server.ex

# lib/my_app/my_server.ex
defmodule MyApp.MyServer do
  @moduledoc """
  An example GenServer that runs arbitrary functions and emits telemetry events when called.
  """
  use GenServer

  # A common prefix for :telemetry events
  @prefix [:my_app, :my_server, :call]

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

  @doc """
  Runs the function contained within this server.

  ## Events

  The following events may be emitted:

    * `[:my_app, :my_server, :call, :start]` - Dispatched
      immediately before invoking the function. This event
      is always emitted.

      * Measurement: `%{system_time: system_time}`

      * Metadata: `%{}`

    * `[:my_app, :my_server, :call, :stop]` - Dispatched
      immediately after successfully invoking the function.

      * Measurement: `%{duration: native_time}`

      * Metadata: `%{}`

    * `[:my_app, :my_server, :call, :exception]` - Dispatched
      immediately after invoking the function, in the event
      the function throws or raises.

      * Measurement: `%{duration: native_time}`

      * Metadata: `%{kind: kind, reason: reason, stacktrace: stacktrace}`
  """
  def call!, do: GenServer.call(__MODULE__, :called)

  @impl true
  def init(fun) when is_function(fun, 0), do: {:ok, fun}

  @impl true
  def handle_call(:called, _from, fun) do
    # Wrap the function invocation in a "span"
    result = telemetry_span(fun)

    {:reply, result, fun}
  end

  # Emits telemetry events related to invoking the function
  defp telemetry_span(fun) do
    start_time = emit_start()

    try do
      fun.()
    catch
      kind, reason ->
        stacktrace = System.stacktrace()
        duration = System.monotonic_time() - start_time
        emit_exception(duration, kind, reason, stacktrace)
        :erlang.raise(kind, reason, stacktrace)
    else
      result ->
        duration = System.monotonic_time() - start_time
        emit_stop(duration)
        result
    end
  end

  defp emit_start do
    start_time_mono = System.monotonic_time()

    :telemetry.execute(
      @prefix ++ [:start],
      %{system_time: System.system_time()},
      %{}
    )

    start_time_mono
  end

  defp emit_stop(duration) do
    :telemetry.execute(
      @prefix ++ [:stop],
      %{duration: duration},
      %{}
    )
  end

  defp emit_exception(duration, kind, reason, stacktrace) do
    :telemetry.execute(
      @prefix ++ [:exception],
      %{duration: duration},
      %{
        kind: kind,
        reason: reason,
        stacktrace: stacktrace
      }
    )
  end
end

並將它新增到應用程式的監督樹狀結構中（通常在 lib/my_app/application.ex），給它一個在呼叫時執行的函數

# lib/my_app/application.ex
children = [
  # Start a server that greets the world
  {MyApp.MyServer, fn -> "Hello, world!" end},
]

現在開始 IEx 會話並呼叫伺服器

iex> MyApp.MyServer.call!

您應該會看到類似下列的輸出

[Telemetry.Metrics.ConsoleReporter] Got new event!
Event name: my_app.my_server.call.stop
All measurements: %{duration: 4000}
All metadata: %{}

Metric measurement: #Function<2.111777250/1 in Telemetry.Metrics.maybe_convert_measurement/2> (summary)
With value: 0.004 millisecond
Tag values: %{}

"Hello, world!"

← 前一頁 Mix 任務

下一頁 → 資產管理