Atusy's blog先日「Rでndjson形式のログを解析する]」の記事を書いた流れで、そういえばRでログを出力する方法を知らないな思ったので調べてみました。
Rでログを扱うパッケージはいくつかありますが、開発が盛んなのはloggerパッケージのようです。最近（2024年8月がごろ）はHadleyも開発に入っているので、安心感がありますね。 loggerパッケージのWebサイトには、類似パッケージの紹介もあるので、他を見当したい場合も、まずはここを見てみるとよいでしょう。
ログを出してみる
とりあえずlogger::log_info関数などにメッセージをあたえればログが出ます。簡単。
logger::log_info("これはINFOログです")
#> INFO [2024-10-25 10:26:09] これはINFOログです
logger::log_warn("これはWARNログです")
#> WARN [2024-10-25 10:26:09] これはWARNログですログの出力レベルを変える
システムの以上を検証したい場合にはINFOログがいらないとか、あるいはDEBUGログを出したいというケースもあるでしょう。このような場合はlogger::log_threshold関数でログの出力レベルを変えます。
普段はINFOログ以上を出すようにしておくといいでしょう（既定値）。
たとえば以下のようにすると、WARN以上のログだけが出力されます。
logger::log_threshold("WARN")
logger::log_info("これはINFOログです。出力されません。")
logger::log_warn("これはWARNログです。出力されます。")
#> WARN [2024-10-25 10:26:09] これはWARNログです。出力されます。ログのフォーマットを変える
先日「Rでndjson形式のログを解析する]」を書いた通り、私はndjson形式のログを好むので、loggerパッケージも対応しているか気になっていました。以下のように簡単に設定できそうで安心しています。
logger::log_formatter(logger::formatter_json)
logger::log_layout(logger::layout_json_parser(fields = c("time", "level", "ns", "fn" )))
logger::log_warn(message = "これはWARNログです")
#> {"time":"2024-10-25 10:26:09","level":"WARN","ns":"global","fn":"eval","message":"これはWARNログです"}ただ、timeフィールドをtimestampフィールドにしたいとか思うと一工夫要りそうです。ここはまた別の機会に調べてみたいと思います。
ログの出力先を変える
t <- tempfile()
logger::log_appender(logger::appender_file(t))
logger::log_warn("これはWARNログです。")
readLines(t)
#> [1] "{\"time\":\"2024-10-25 10:26:09\",\"level\":\"WARN\",\"ns\":\"global\",\"fn\":\"eval\",\"5\":\"これはWARNログです。\"}"logger::appender_tee関数を使うと、コンソールとファイルの両方に出力することもできます。とりあえずログを眺めたいけど、あとでも使いたいなんてケースに便利そうですね。
コンソールにはINFO以上のログを出して、ファイルにはDEBUGログも出すとかできても便利そうですが、その場合は時前実装が必要な気配です。
気になること
便利関数の機能
loggerパッケージは便利関数をいくつか用意しているので試してみたいところ。
message関数やwarning関数の出力をログに転送する機能- Shinyアプリケーションでユーザー入力の変更をログに転送する機能
パッケージ開発での利用
パッケージ開発でもロガーを仕込むとデバグしやすくなりそうだなと思いました。しかし、loggerパッケージでは設定に使う関数（logger::logger_thresholdなど）が全体に適用されないか気になってます。
たとえば、パッケージ側ではデフォルトでWARN以上のログを出力するようにしていて、ユーザーが時前のスクリプトのINFOログを出すことにした時、パッケージ側のINFOログも出てしまわないかとか。パッケージ開発にも使いやすいよう、良い感じに設定を切り替えるぜって書いてるので大丈夫かなーとは思ってます。
automatically finding and creating a custom namespace for all R packages writing log messages
ちなみにPythonのloggingモジュールの場合、get_loggerで作成したロガーそれぞれに対して設定を変更できます。こっちの方が分かりやすいなーとも思いますが、いかにもオブジェクト指向な感じです。
RのloggerパッケージはRらしい書き方を追求したのかなと思います。
import logging
logger0 = logging.getLogger("logger0")
logger1 = logging.getLogger("logger1")
logger1.setLevel(logging.ERROR)
# logger0はERRORログ以外も出せる
logger0.warning("This is WARN log from logger0")
#> This is WARN log from logger0
logger0.error("This is ERROR log from logger0")
#> This is ERROR log from logger0
# logger1はERRORログだけ出せる
logger1.warning("This is WARN log from logger1")
logger1.error("This is ERROR log from logger1")
#> This is ERROR log from logger1ログローテーション
ログをファイルに出力する場合、サイズが大きくなるとメモリやディスクを逼迫する可能性があります。これを避ける方法として、ログの書き込み先変更や、古いログの削除が一般的です。 loggerパッケージでもこれらを実現する方法があるのか気になります。
ENJOY
loggerパッケージ、いい感じですね。本格的に使うにはまだ調査が足りませんが、手元の分析ログを出したい時などには十分使えそうに思いました。