[クロス本草稿]ロギング


本文章は、技術書典5にて[project daisy bell]( https://twitter.com/MNukazawa )がリリースする予定の、クロスプラットホーム・デスクトップアプリケーション・GUIフレームワーク・クロスレビュー本(仮)(以下、クロス本)の一部の草稿です。
クロス本は、筆者のGTK/Qt/Electronの経験と知見について扱います。具体的な解説書というより技術エッセイです。
本文章には、校正前の文章・記憶により記述し未確認の内容・雑なmarkdown風紀法・張ってないURLリンク、などがあります。



# ロギング

本物のデスクトップアプリケーションは、バグレポートに添付して原因を解析可能な、本物のデバッグログ(動作ログ)が出力されるべきである。
デバッグログは、アプリケーションの開発中・ユーザ環境での実運用中の両方で、常に出力され続けなければならない。
本章では、デスクトップアプリケーションからのデバッグログのファイル書き出しについて扱う。
開発中のデバッグ手法は基本的には開発環境の章で扱うが、本章で扱う動作ログも無関係ではない。



GTKにはデバッグログのための機構はない。
QtにはデバッグログのためのqDebug()関数群が用意されている。
Electronではconsole.log()関数群を用いる。
筆者は、Electronでは動作ログのファイル書き出しを行っていないため、それは扱わない。
本章は、GTK,Qt,Electron固有のテクニックと言うより、C,C++での文字列操作テクニックや、筆者の方針が多い内容になっている。

デスクトップアプリケーションでのロギングは下記が参考になる。
[Joel on Software やさしいバグトラッキング]( http://local.joelonsoftware.com/wiki/やさしいバグトラッキング )
[Joel on Software ユーザからクラッシュレポートを自動的に取得する方法]( https://www.amazon.co.jp/Joel-Software-Spolsky/dp/4274066304 )
ただ、筆者は上記に書いてあるようなクラッシュレポートの収集はまだ実施できていない。

マルチプラットフォームを考えると、syslog()が使えない。

筆者は、以下の通りにしている。
- デバッグログはファイルに書き出す
- 標準出力,標準エラー出力からリダイレクトしてテキストファイルに書き出すようにする場合もある
- 基本的に、ログにASCII文字以外は使わない
- 上記を前提に、マルチプラットフォーム(Windows)で日本語出力した場合に起こるかもしれない文字化けは基本的に最初から諦める
- フォーマッティングに難があるため、"+"演算子やstreamによる文字列連結を避ける
- 必要があれば独自実装の簡易なログローテーション(削除や圧縮)を行う
- 起動時にアプリケーションのversion情報をdumpする(手動でインクリメントされるリリース番号だけでなく、gitのコミットハッシュ等をバイナリに織り込んで用いる)

streamについて。
フォーマッティングの文法が長くコードの読み書きが難しいため、極力使用を避けている。

ログローテーションについて。
ログファイル名に起動時刻を使用し、アプリケーション起動時に一週間より古い名前の付いたログファイルを検出して、それらをzipするコマンドを叩く、という実装を行った。
なお、zip圧縮はアーカイブに後からファイルを追加していくことができる。
必要なければzip圧縮でなく単に削除するようにすればよい。
Windowsでは標準コマンドが機能不足であったため、[7-Zip コマンドラインバージョン(7za.exe)]( https://sevenzip.osdn.jp/download.html )をバイナリに添付して用いた。
Linuxでは標準のzipコマンドを呼び出せば用が足りる。
MacOSXでは行っていないが、たぶんLinuxと同じ方法で行ける。

アプリケーションのversion情報について。
過去にはビルド日時も入れていたが、これはビルド毎にバイナリハッシュが変わるだけで意味はないため、最近は行っていない。
gitコミットハッシュを付与する際、未commitな変更がないか確認して存在すればその旨("-develop"など)を付与するようにしている。
[vecterion/version.sh]( https://github.com/MichinariNukazawa/vecterion_vge/blob/master/version.sh )
一部抜粋
```bash
# repository
GIT_HASH=$(git log --pretty=format:'%h' -n 1)
GIT_BRANCH=$(git branch | awk '/^\*/ { printf $2 }')
GIT_DATETIME=$(git log --date=iso --pretty=format:"%ad" -n 1)
## @todo can't check to unstaging new file.
GIT_STATUS_SHORT=$(git diff --stat | tail -1)
```
が、gitで未コミットファイルの十分な判定が未解決の問題となっている。
(未ステージングな新しいファイルが存在する場合にそれを検出する良い方法が見つかっていない。)
また、この方法はQt(QtCreator)では、qmakeファイル(.pro)に組み込むことが難しい。
(QtCreatorから外部のMakefileを呼び出すようにしたら、Makefileを呼び出すだけでヌルビルドに4秒余分にかかるようになってしまった)

## GTK

GTKには、GTKライブラリ側のデバッグオプションがあるが、筆者はこれを使ったことがない。
[Running and debugging GTK+ Applications]( https://developer.gnome.org/gtk3/stable/gtk-running.html )

内容が完全にC言語マクロテクニックになってしまうが、筆者は下記の関数マクロを使用している。
[vecterion/include/pv_error.h]( https://github.com/MichinariNukazawa/vecterion_vge/blob/master/include/pv_error.h )
一部抜粋
```c
#define pv_error(fmt, ...)  \
    fprintf(stderr, "error: %s()[%d]: "fmt"\n", __func__, __LINE__, ## __VA_ARGS__)
```
呼び出すマクロでレベルを指定する。
コード上の関数名と行番号を自動付与する。
vecterionでは、関数名があればファイル名が無くてもログの出力箇所が一意に特定できるため、ファイル名は付けていなかった。
(pc_critical()でexit()を呼んでいないのは、筆者が修行不足であったが故。ここはサパっと死ぬべきだった。)

なお、gtkにはg_strdup_new()というユーティリティ関数がある。
これはprintフォーマットで生成した文字列を必要なメモリを確保して入れて返す。確保するので開放する必要もある。

日本語出力した場合どうなっていたか覚えていないが、多分コマンドプロンプトは文字化けする。

## Qt

QtにはqDebug()関数群がある。
呼び出す関数でレベルを指定する。
環境により出力先を切り分けてくれるようなのだが、常にトラップしてファイル出力していたため、筆者は詳細を知らない。
トラップは[qInstallMessageHandler()]( http://doc.qt.io/qt-5/qtglobal.html#qInstallMessageHandler )で行う。
[QDebug Class]( http://doc.qt.io/qt-5/qdebug.html )
[What's New in Qt 5.6.0: Logging to syslog and journald]( https://www.ics.com/blog/whats-new-qt-560-logging-syslog-and-journald )
ドキュメントに使用例でQRectをそのままストリームに渡しているところを見ると、QObjectを渡すだけで適切にデバッグ出力してくれるのかもしれない。

qDebug()はprintフォーマットでないため、16進数やゼロ埋めを使ったデバッグ出力が欲しい場合に苦労した。
(筆者はc++開発では一般にprintフォーマットが存在しないため苦労する。)
QStringにformatという似た機能があったため、なんとかやっていた。
下記使用例はうろ覚え。
```c++
qDebug(QString::format("%1,%2")
    .arg(hex_value, 16)
    .arg(space_fill_value, 3, 10, QChar(' ')))))
    // hex_valueは、続く第二引数が16進数表記を表す
    // space_fill_valueは、続く第二引数が桁数で第三引数が10進数表記を表す(!)、第四引数が埋めに使う文字
```

str.sprint()というメソッドがあり、筆者はこれも使っていた。
staticメンバではないため、QStringのオブジェクトを用意する必要がある。
下記使用例はうろ覚えだったため[stackoverflow]( https://stackoverflow.com/questions/4784155/how-to-format-a-qstring )より改変引用。
```c++
QString str;
qDebug(str.sprintf("%s %d", "string", 213));
```
2018年現在のQt5.11のドキュメントには無いため廃止された模様。

公式ドキュメントによると、古いversionのQtではqDebug()でprintフォーマットが使えた模様。
[Qt3.3 qDebug()]( http://doc.qt.io/archives/3.3/qapplication.html#qDebug )
2018年現在のQt5.11のドキュメントには無い使用法なので、廃止されたものと思われる。

アプリケーションversion番号のgit hasuについては、よく覚えていない。
確か最終的に.proファイルにコマンド出力をマクロ変数(?)に格納する記法があり、それを用いて「.proのマクロから、c++プリプロセッサマクロ置換」、で実装したような気がする。

Qtと関係ない、純粋なC++言語マクロテクニックの話になってしまうが、MicrosoftのMSDNマガジンで書かれたstd::stringをprintフォーマットに渡せるTempleteテクニックがあり、とても気に入っている。
[最新の C++ で Printf を使用する]( https://msdn.microsoft.com/ja-jp/magazine/dn913181.aspx )

日本語出力がどうなるかは覚えていないが、多分Qt(qDebug())側でハンドリングしているのではないかと思う。

## Electron

console.log()でする。
呼び出すメソッドでレベルを指定する。
デバッグコンソールでログレベルをverboseにしておかないとconsole.debug()が出力に表示されないので注意。

chromium由来のconsole.log()には、いくつかの拡張機能が用意されている。
(どうやら他ブラウザに無い場合があるようで、たぶん標準でない...といっても厳密にはECMAScript仕様にはconsole.log()関数は存在しないのではないかと思うが)
- オブジェクトだけを引数に入れるとコンソールでオブジェクトを展開できる
- 簡単なprintフォーマットが使える

lina_dictoではファイル出力等はしていない。
今後本格的なアプリを書いた場合の課題になっている、未解決問題。
たぶんnpmに選ぶのに困るほど多くのロギングパッケージがあるだろうと考えている。

jsのasyncなメソッドをfor,loop内で同期的に呼び出す

async/awaitを使ったjavascriptのコードをnodejsで使用する際、非同期呼び出しとなっている関数をloopの中で動機呼び出しする方法。 この前かなり真剣にPromiseのドキュメントを読んで、これをいずれ使うことになるのか、使いこなすの大変そうだな、と思っ...