ロギング

ロギングはソフトウェア開発の重要な側面であり、特にアプリケーションのデバッグと挙動のモニタリングにおいて不可欠です。このセクションでは、Effect のロギングユーティリティに深く掘り下げ、従来のconsole.logのような方法に対する利点を探ります。

従来のロギングに対する利点

Effect のロギングユーティリティは、従来のロギング方法console.logに対していくつかの利点を提供します。

動的ログレベルコントロール: Effect のロギングを使用すると、ログレベルを動的に変更することができます。これは、メッセージの重要度に応じて表示するログメッセージを制御できることを意味します。たとえば、アプリケーションを設定して警告やエラーのみをログに記録させることができ、これは生産環境でノイズを軽減するのに非常に役立ちます。
カスタムロギング出力: Effect のロギングユーティリティでは、ログの処理方法を変更できます。カスタムロガーを使用して、ログメッセージをさまざまな宛先（サービスやファイルなど）に送信することができます。この柔軟性により、アプリケーションの要件に最も適した方法でログが保存され処理されます。
詳細なロギング: Effect はプログラムの部分ごとにロギングを詳細に制御できます。アプリケーションの異なる部分に対して異なるログレベルを設定でき、各特定のコンポーネントに対して詳細レベルを調整できます。これはデバッグやトラブルシューティングにとって貴重です。重要な情報に焦点を当てることができます。
環境ベースのロギング: Effect のロギングユーティリティは、デプロイ環境と組み合わせて詳細なロギング戦略を実現できます。たとえば、開発中は詳細なデバッグのためにトレースレベル以上のすべてをログに記録することを選択するかもしれません。対照的に、生産版はエラーや重大な問題のみをログに記録するように設定でき、パフォーマンスへの影響や生産ログにおけるノイズを最小限に抑えます。
追加機能: Effect のロギングユーティリティには、タイムスパンを測定したり、エフェクトごとにログレベルを変更したり、パフォーマンスモニタリングのためにスパンを統合したりするなどの追加機能があります。

では、Effect が提供する特定のロギングユーティリティを見ていきましょう。

log

Effect.log関数は、デフォルトのINFOレベルでログメッセージを出力します。

import { Effect } from "effect";

const program = Effect.log("アプリケーションが開始されました");

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message="アプリケーションが開始されました"
*/

デフォルトのロガーを使用してEffect.logを使うと、各ログエントリにいくつかの重要な詳細が組み込まれます。

timestamp: ログメッセージが生成された時刻。
level: メッセージがログに記録されたログレベル。
fiber: プログラムを実行しているファイバーの識別子。
message: ログ内容（複数のアイテムを含むことができる）。
span: （オプション）spanのミリ秒単位の期間。

特定のニーズに合わせてロギング設定を調整する方法について、カスタムロギングフレームワークの統合やログ形式の調整など、カスタムロガーのセクションを参照してください。

複数のメッセージを同時にログに記録できます：

import { Effect } from "effect";

const program = Effect.log("メッセージ1", "メッセージ2", "メッセージ3");

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message=メッセージ1 message=メッセージ2 message=メッセージ3
*/

コンテキストを追加するために、1 つ以上のCauseインスタンスをログに含めることもでき、これによって追加のcause注釈の下で詳細なエラー情報が提供されます。

import { Effect, Cause } from "effect";

const program = Effect.log(
  "メッセージ1",
  "メッセージ2",
  Cause.die("ああ！"),
  Cause.die("おっと！")
);

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message=メッセージ1 message=メッセージ2 cause="Error: ああ！
Error: おっと！"
*/

ログレベル

logDebug

デフォルトでは、DEBUGメッセージは出力されません。

ただし、Logger.withMinimumLogLevelを使用してデフォルトロガーを構成し、最小ログレベルをLogLevel.Debugに設定することで有効にできます。

以下は、特定のタスク（task1）のためにDEBUGメッセージを有効にする方法を示す例です。

Using Effect.gen
Using pipe

import { Effect, Logger, LogLevel } from "effect";

const task1 = Effect.gen(function* () {
  yield* Effect.sleep("2 seconds");
  yield* Effect.logDebug("task1 完了");
}).pipe(Logger.withMinimumLogLevel(LogLevel.Debug));

const task2 = Effect.gen(function* () {
  yield* Effect.sleep("1 second");
  yield* Effect.logDebug("task2 完了");
});

const program = Effect.gen(function* () {
  yield* Effect.log("開始");
  yield* task1;
  yield* task2;
  yield* Effect.log("完了");
});

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO message=開始
timestamp=... level=DEBUG message="task1 完了" <-- 2秒後
timestamp=... level=INFO message=完了 <-- 1秒後
*/

import { Effect, Logger, LogLevel } from "effect";

const task1 = Effect.sleep("2 seconds").pipe(
  Effect.andThen(Effect.logDebug("task1 完了")),
  Logger.withMinimumLogLevel(LogLevel.Debug)
);

const task2 = Effect.sleep("1 second").pipe(
  Effect.andThen(Effect.logDebug("task2 完了"))
);

const program = Effect.log("開始").pipe(
  Effect.andThen(task1),
  Effect.andThen(task2),
  Effect.andThen(Effect.log("完了"))
);

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO message=開始
timestamp=... level=DEBUG message="task1 完了" <-- 2秒後
timestamp=... level=INFO message=完了 <-- 1秒後
*/

上記の例では、Logger.withMinimumLogLevel関数を使用してtask1に対して特にDEBUGメッセージを有効にしています。

Logger.withMinimumLogLevel(effect, level)を使用することで、プログラム内の特定のエフェクトに対して異なるログレベルを選択的に有効にする柔軟性があります。これにより、ログの詳細度を制御し、デバッグやトラブルシューティングに最も関連する情報に焦点を当てることができます。

logInfo

デフォルトでは、INFOメッセージが出力されます。

Using Effect.gen
Using pipe

import { Effect } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.logInfo("開始");
  yield* Effect.sleep("2 seconds");
  yield* Effect.sleep("1 second");
  yield* Effect.logInfo("完了");
});

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO message=開始
timestamp=... level=INFO message=完了 <-- 3秒後
*/

import { Effect } from "effect";

const program = Effect.logInfo("開始").pipe(
  Effect.andThen(Effect.sleep("2 seconds")),
  Effect.andThen(Effect.sleep("1 second")),
  Effect.andThen(Effect.logInfo("完了"))
);

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO message=開始
timestamp=... level=INFO message=完了 <-- 3秒後
*/

上記の例では、Effect.log関数を使用してINFOメッセージを"開始"と"完了"でログに記録しています。これらのメッセージはプログラムの実行中に出力されます。

logWarning

デフォルトでは、WARNメッセージが出力されます。

Using Effect.gen
Using pipe

import { Effect, Either } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = Effect.gen(function* () {
  const failureOrSuccess = yield* Effect.either(task);
  if (Either.isLeft(failureOrSuccess)) {
    yield* Effect.logWarning(failureOrSuccess.left);
    return 0;
  } else {
    return failureOrSuccess.right;
  }
});

Effect.runFork(program);
/*
出力:
timestamp=... level=WARN fiber=#0 message="おっと！"
*/

import { Effect } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = task.pipe(
  Effect.catchAll((error) => Effect.logWarning(error).pipe(Effect.as(0)))
);

Effect.runFork(program);
/*
出力:
timestamp=... level=WARN fiber=#0 message="おっと！"
*/

logError

デフォルトでは、ERRORメッセージが出力されます。

Using Effect.gen
Using pipe

import { Effect, Either } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = Effect.gen(function* () {
  const failureOrSuccess = yield* Effect.either(task);
  if (Either.isLeft(failureOrSuccess)) {
    yield* Effect.logError(failureOrSuccess.left);
    return 0;
  } else {
    return failureOrSuccess.right;
  }
});

Effect.runFork(program);
/*
出力:
timestamp=... level=ERROR fiber=#0 message="おっと！"
*/

import { Effect } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = task.pipe(
  Effect.catchAll((error) => Effect.logError(error).pipe(Effect.as(0)))
);

Effect.runFork(program);
/*
出力:
timestamp=... level=ERROR fiber=#0 message="おっと！"
*/

logFatal

デフォルトでは、FATALメッセージが出力されます。

Using Effect.gen
Using pipe

import { Effect, Either } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = Effect.gen(function* () {
  const failureOrSuccess = yield* Effect.either(task);
  if (Either.isLeft(failureOrSuccess)) {
    yield* Effect.logFatal(failureOrSuccess.left);
    return 0;
  } else {
    return failureOrSuccess.right;
  }
});

Effect.runFork(program);
/*
出力:
timestamp=... level=FATAL fiber=#0 message="おっと！"
*/

import { Effect } from "effect";

const task = Effect.fail("おっと！").pipe(Effect.as(2));

const program = task.pipe(
  Effect.catchAll((error) => Effect.logFatal(error).pipe(Effect.as(0)))
);

Effect.runFork(program);
/*
出力:
timestamp=... level=FATAL fiber=#0 message="おっと！"
*/

カスタムアノテーション

Effect.annotateLogs関数を使用してカスタムアノテーションをログ出力に組み込むことで、効果の各ログエントリに追加のメタデータを追加し、トレース可能性とコンテキストを向上させることができます。

ここでは、キー/バリューのペアとして単一のアノテーションを適用する方法を示します：

import { Effect } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("メッセージ1");
  yield* Effect.log("メッセージ2");
}).pipe(Effect.annotateLogs("key", "value")); // キー/バリューのペアとしてのアノテーション

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message=メッセージ1 key=value
timestamp=... level=INFO fiber=#0 message=メッセージ2 key=value
*/

複数のアノテーションを同時に適用する場合は、複数のキー/バリューのペアを含むオブジェクトを渡すことができます：

import { Effect } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("メッセージ1");
  yield* Effect.log("メッセージ2");
}).pipe(Effect.annotateLogs({ key1: "value1", key2: "value2" }));

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message=メッセージ1 key2=value2 key1=value1
timestamp=... level=INFO fiber=#0 message=メッセージ2 key2=value2 key1=value1
*/

アノテーションは、Effect.annotateLogsScopedを使用してスコープ付きライフタイムで適用することもできます。このメソッドは、エフェクト計算の特定のスコープにおけるログでアノテーションの適用を制限します。

import { Effect } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("アノテーションなし");
  yield* Effect.annotateLogsScoped({ key: "value" });
  yield* Effect.log("メッセージ1"); // このログにアノテーションが適用されます
  yield* Effect.log("メッセージ2"); // このログにアノテーションが適用されます
}).pipe(Effect.scoped, Effect.andThen(Effect.log("アノテーションなし 再び")));

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message="アノテーションなし"
timestamp=... level=INFO fiber=#0 message=メッセージ1 key=value
timestamp=... level=INFO fiber=#0 message=メッセージ2 key=value
timestamp=... level=INFO fiber=#0 message="アノテーションなし 再び"
*/

ログスパン

Effect はまた、プログラム内の特定の操作やタスクの期間を測定するためのログスパンをサポートしています。

Using Effect.gen
Using pipe

import { Effect } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.sleep("1 second");
  yield* Effect.log("作業が完了しました！");
}).pipe(Effect.withLogSpan("myspan"));

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message="作業が完了しました！" myspan=1011ms
*/

import { Effect } from "effect";

const program = Effect.sleep("1 second").pipe(
  Effect.andThen(Effect.log("作業が完了しました！")),
  Effect.withLogSpan("myspan")
);

Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message="作業が完了しました！" myspan=1011ms
*/

上記の例では、Effect.withLogSpan(label)関数を使用してログスパンを作成します。これは、スパン内のコードブロックの期間を測定します。結果として得られた期間は、自動的にログメッセージ内の注釈として記録されます。

デフォルトロギングの無効化

テスト実行中にデフォルトロギングをオフにする必要がある場合があります。このセクションでは、Effect フレームワーク内でデフォルトロギングを無効にするさまざまな方法を探索します。

withMinimumLogLevel を使用

Effect は、最小ログレベルを設定する便利な関数withMinimumLogLevelを提供しており、これによりログを無効化できます。

import { Effect, Logger, LogLevel } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("タスクを実行中...");
  yield* Effect.sleep("100 millis");
  console.log("タスク完了");
});

// ロギング有効（デフォルト）
Effect.runFork(program);
/*
出力:
timestamp=... level=INFO fiber=#0 message="タスクを実行中..."
タスク完了
*/

// withMinimumLogLevelを使ってロギングを無効化
Effect.runFork(program.pipe(Logger.withMinimumLogLevel(LogLevel.None)));
/*
出力:
タスク完了
*/

ログレベルをLogLevel.Noneに設定することで、ロギングを無効にし、最終結果だけを表示します。

レイヤーを使用

ロギングを無効にする別のアプローチは、最小ログレベルをLogLevel.Noneに設定するレイヤーを作成することです。これにより、すべてのロギングが無効になります。

import { Effect, Logger, LogLevel } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("タスクを実行中...");
  yield* Effect.sleep("100 millis");
  console.log("タスク完了");
});

const layer = Logger.minimumLogLevel(LogLevel.None);

// レイヤーを使用してロギングを無効化
Effect.runFork(program.pipe(Effect.provide(layer)));
/*
出力:
タスク完了
*/

カスタムランタイムの使用

カスタムランタイムを作成して、ロギングを無効にする設定を含めることでもロギングを無効化できます。

import { Effect, Logger, LogLevel, ManagedRuntime } from "effect";

const program = Effect.gen(function* () {
  yield* Effect.log("タスクを実行中...");
  yield* Effect.sleep("100 millis");
  console.log("タスク完了");
});

const customRuntime = ManagedRuntime.make(
  Logger.minimumLogLevel(LogLevel.None)
);

customRuntime.runPromise(program);
/*
出力:
タスク完了
*/

このアプローチでは、ロギングを無効にする設定を含むカスタムランタイムを作成し、そのカスタムランタイムを使用してプログラムを実行します。

構成からのログレベルの読み込み

ログレベルを構成から取得し、プログラムに組み込むには、Logger.minimumLogLevelから生成されたレイヤーを利用します：

import {
  Effect,
  Config,
  Logger,
  Layer,
  ConfigProvider,
  LogLevel,
} from "effect";

// ログを持つプログラムのシミュレーション
const program = Effect.gen(function* () {
  yield* Effect.logError("ERROR!");
  yield* Effect.logWarning("WARNING!");
  yield* Effect.logInfo("INFO!");
  yield* Effect.logDebug("DEBUG!");
});

// 構成からログレベルをレイヤーとしてロード
const LogLevelLive = Config.logLevel("LOG_LEVEL").pipe(
  Effect.andThen((level) => Logger.minimumLogLevel(level)),
  Layer.unwrapEffect
);

// 読み込まれたログレベルでプログラムを構成
const configured = Effect.provide(program, LogLevelLive);

// ConfigProvider.fromMapを使用して構成されたプログラムをテスト
const test = Effect.provide(
  configured,
  Layer.setConfigProvider(
    ConfigProvider.fromMap(new Map([["LOG_LEVEL", LogLevel.Warning.label]]))
  )
);

Effect.runFork(test);
/*
出力:
... level=ERROR fiber=#0 message=ERROR!
... level=WARN fiber=#0 message=WARNING!
*/

構成されたプログラムを評価するには、テスト用のConfigProvider.fromMapを使用できます（詳細についてはテストサービスを参照）。

カスタムロガー

このセクションでは、カスタムロガーを定義し、それをデフォルトのロガーとして設定する方法を学びます。

まず、Logger.makeを使用してカスタムロガーを定義します：

import { Logger } from "effect";

export const logger = Logger.make(({ logLevel, message }) => {
  globalThis.console.log(`[${logLevel.label}] ${message}`);
});

カスタムロガーを定義したと仮定すると、次にプログラムを定義します。

Using Effect.gen
Using pipe

import { Effect } from "effect";

const task1 = Effect.gen(function* () {
  yield* Effect.sleep("2 seconds");
  yield* Effect.logDebug("task1 完了");
});

const task2 = Effect.gen(function* () {
  yield* Effect.sleep("1 second");
  yield* Effect.logDebug("task2 完了");
});

export const program = Effect.gen(function* () {
  yield* Effect.log("開始");
  yield* task1;
  yield* task2;
  yield* Effect.log("完了");
});

import { Effect } from "effect";

const task1 = Effect.sleep("2 seconds").pipe(
  Effect.andThen(Effect.logDebug("task1 完了"))
);

const task2 = Effect.sleep("1 second").pipe(
  Effect.andThen(Effect.logDebug("task2 完了"))
);

export const program = Effect.log("開始").pipe(
  Effect.andThen(task1),
  Effect.andThen(task2),
  Effect.andThen(Effect.log("完了"))
);

デフォルトロガーを置き換えるには、Logger.replaceを使用して特定のレイヤーを作成し、実行前にEffect.provideを使用して提供するだけです。

import { Effect, Logger, LogLevel } from "effect";
import * as CustomLogger from "./CustomLogger";
import { program } from "./program";

// デフォルトロガーをカスタムロガーで置き換え
const layer = Logger.replace(Logger.defaultLogger, CustomLogger.logger);

Effect.runFork(
  program.pipe(
    Logger.withMinimumLogLevel(LogLevel.Debug),
    Effect.provide(layer)
  )
);

プログラムを実行後、コンソールに表示される内容は以下の通りです：

[INFO] 開始
[DEBUG] task1 完了
[DEBUG] task2 完了
[INFO] 完了

組み込みロガー

json

jsonロガーは、ログエントリを JSON オブジェクトとしてフォーマットし、JSON データを消費するロギングシステムとの統合を容易にします。

import { Effect, Logger } from "effect";

const program = Effect.log("メッセージ1", "メッセージ2").pipe(
  Effect.annotateLogs({ key1: "value1", key2: "value2" }),
  Effect.withLogSpan("myspan")
);

Effect.runFork(program.pipe(Effect.provide(Logger.json)));
// {"message":["メッセージ1","メッセージ2"],"logLevel":"INFO","timestamp":"...","annotations":{"key2":"value2","key1":"value1"},"spans":{"myspan":0},"fiberId":"#0"}

logFmt

このロガーは、開発中や生産コンソールでも分かりやすい人間が読みやすい形式でログを出力します。

import { Effect, Logger } from "effect";

const program = Effect.log("メッセージ1", "メッセージ2").pipe(
  Effect.annotateLogs({ key1: "value1", key2: "value2" }),
  Effect.withLogSpan("myspan")
);

Effect.runFork(program.pipe(Effect.provide(Logger.logFmt)));
// timestamp=... level=INFO fiber=#0 message=メッセージ1 message=メッセージ2 myspan=0ms key2=value2 key1=value1

structured

structured ロガーは、イベントの追跡可能性を保持するために構造化された詳細なログ出力を提供し、深い分析やトラブルシューティングに適しています。

import { Effect, Logger } from "effect";

const program = Effect.log("メッセージ1", "メッセージ2").pipe(
  Effect.annotateLogs({ key1: "value1", key2: "value2" }),
  Effect.withLogSpan("myspan")
);

Effect.runFork(program.pipe(Effect.provide(Logger.structured)));
/*
{
  message: [ 'メッセージ1', 'メッセージ2' ],
  logLevel: 'INFO',
  timestamp: '2024-07-09T14:05:41.623Z',
  cause: undefined,
  annotations: { key2: 'value2', key1: 'value1' },
  spans: { myspan: 0 },
  fiberId: '#0'
}
*/

pretty

prettyロガーは、console API の機能を利用して視覚的に魅力的で色付けされたログ出力を生成します。この機能は、開発やデバッグプロセス中にログメッセージの可読性を向上させるのに特に役立ちます。

import { Effect, Logger } from "effect";

const program = Effect.log("メッセージ1", "メッセージ2").pipe(
  Effect.annotateLogs({ key1: "value1", key2: "value2" }),
  Effect.withLogSpan("myspan")
);

Effect.runFork(program.pipe(Effect.provide(Logger.pretty)));
/*
        green --v                      v-- bold and cyan
[07:51:54.434] INFO (#0) myspan=1ms: メッセージ1
  メッセージ2
   v-- bold
  key2: value2
  key1: value1
*/

ログレベルは次のように色付けされています：

ログレベル	色
トレース	グレー
デバッグ	青
情報	緑
警告	黄色
エラー	赤
致命的	白背景の赤