Skip to content
This repository has been archived by the owner on Apr 12, 2023. It is now read-only.

「ログ出力時に毎回ファイルを開いている」の修正 #67

Open
wants to merge 27 commits into
base: feature/log_improvement
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 8 commits
Commits
Show all changes
27 commits
Select commit Hold shift + click to select a range
de947fc
LogWriter 作成
Takym Mar 19, 2021
94b7d96
LoggerService のコンストラクタ変更に関する修正
Takym Mar 19, 2021
d0b4d44
CONTRIBUTORS.md 更新
Takym Mar 19, 2021
36b68b0
CreateLogRow を修正
Takym May 3, 2021
082a089
lock を Interlocked に変更
Takym May 3, 2021
016beb2
Merge branch 'master' into logging
Takym May 3, 2021
a9b4b62
Merge branch 'logging' of https://github.com/Takym/cocoa into logging
Takym May 3, 2021
e72f0da
Update Covid19Radar/Covid19Radar/Services/Logs/LogWriter.cs
Takym May 11, 2021
b459354
ソースファイルの書式を修正
Takym May 11, 2021
cfc16a0
Merge branch 'logging' of https://github.com/Takym/cocoa into logging
Takym May 11, 2021
a00563a
`CreateLogRow` を微修正
Takym May 11, 2021
03f7fab
フィールド名修正
Takym May 16, 2021
a68cac6
`_file` フィールドの書き換え処理を改善
Takym May 18, 2021
b4f15d8
`WriteLine(DateTime, string)` を改善
Takym May 18, 2021
2f6002d
`WriteLine(DateTime, string)` を微修正
Takym May 18, 2021
68b7d9f
`HEADER` の出力タイミングを修正
Takym May 18, 2021
f4986d2
テスト処理修正
Takym May 18, 2021
186a323
CreateLogRow、可読性&性能向上
Takym May 22, 2021
72a4f73
可読性&性能向上2
Takym May 22, 2021
c4bec33
`LogWriter.File` クラス改名
Takym Jun 5, 2021
09eaa47
LogWriter、フィールド変数の名前を変更
Takym Jun 5, 2021
c00b730
`LogWriter.LogFile` の仕組みを変更
Takym Jun 5, 2021
a4b32c0
`LogWriter.WriteLine` のローカル変数の名前を変更
Takym Jun 5, 2021
bc848ce
`LogWriter.LogFile.FileName` を **Path** に改名
Takym Jun 5, 2021
af59231
Merge branch 'cocoa-mhlw:develop' into logging
Takym Jun 11, 2021
b0a617c
Merge branch 'cocoa-mhlw:develop' into logging
Takym Jul 1, 2021
ac1f49f
Update unit tests for the logging system. (Takym/cocoa#4)
Takym Aug 20, 2021
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CONTRIBUTORS.md
Original file line number Diff line number Diff line change
Expand Up @@ -75,6 +75,7 @@
- Tassana Thaveeteeratham (Thai Translation)
- Kotaro Sakamoto
- Koichi Yokota (Documentation)
- Takym (LogWriter)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

CONTRIBUTORに関しては新しく項目を設けますね。


# Original Covid19Radar Beta Testers
- Nagahata Kenji
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -61,7 +61,7 @@ public LogPeriodicDeleteReceiver()
{
var essensialService = new EssentialsService();
var logPathService = new LogPathService(new LogPathServiceAndroid());
loggerService = new LoggerService(logPathService, essensialService);
loggerService = new LoggerService(new LogWriter(logPathService, essensialService));
logFileService = new Covid19Radar.Services.Logs.LogFileService(loggerService, logPathService);
Comment on lines 62 to 65
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

この部分だけServiceLocatorから外れていて、Singleton保てていないんですね。
話がややこしくなりそうなので、ここをServiceLocator化するPull Request出すことにします。

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LogPeriodicDeleteServiceAndroid の様に DependencyService.Resolve<T>() を使えば良いと思います。

Copy link
Contributor Author

@Takym Takym Jun 7, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

似た問題として #185#189 を確認しました。

}

Expand Down
3 changes: 2 additions & 1 deletion Covid19Radar/Covid19Radar/App.xaml.cs
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ public partial class App : PrismApplication
private ILoggerService LoggerService;
private ILogFileService LogFileService;

/*
/*
* The Xamarin Forms XAML Previewer in Visual Studio uses System.Activator.CreateInstance.
* This imposes a limitation in which the App class must have a default constructor.
* App(IPlatformInitializer initializer = null) cannot be handled by the Activator.
Expand Down Expand Up @@ -166,6 +166,7 @@ private static void RegisterCommonTypes(IContainer container)
container.Register<ILogPathService, LogPathService>(Reuse.Singleton);
container.Register<ILogPeriodicDeleteService, LogPeriodicDeleteService>(Reuse.Singleton);
container.Register<ILogUploadService, LogUploadService>(Reuse.Singleton);
container.Register<ILogWriter, LogWriter>(Reuse.Singleton);
container.Register<IEssentialsService, EssentialsService>(Reuse.Singleton);
container.Register<IUserDataService, UserDataService>(Reuse.Singleton);
container.Register<IExposureNotificationService, ExposureNotificationService>(Reuse.Singleton);
Expand Down
210 changes: 210 additions & 0 deletions Covid19Radar/Covid19Radar/Services/Logs/LogWriter.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,210 @@
#nullable enable
keiji marked this conversation as resolved.
Show resolved Hide resolved

using System;
using System.Diagnostics;
using System.IO;
using System.Text;
using System.Threading;
using Covid19Radar.Common;

namespace Covid19Radar.Services.Logs
{
/// <summary>
/// ログの書き込みを行う機能を提供します。
/// </summary>
public interface ILogWriter : IDisposable
{
/// <summary>
/// ログを出力します。
/// </summary>
/// <param name="message">出力するメッセージです。</param>
/// <param name="method">実行中の関数の名前です。</param>
/// <param name="filePath">実行中の関数を格納しているソースファイルの名前です。</param>
/// <param name="lineNumber">実行中の関数のソースファイル内での行番号です。</param>
/// <param name="logLevel">ログレベルです。</param>
public void Write(string message, string method, string filePath, int lineNumber, LogLevel logLevel);
}

/// <summary>
/// <see cref="Covid19Radar.Services.Logs.ILogWriter"/>の実装です。
/// </summary>
public sealed class LogWriter : ILogWriter
{
private const string _dt_format = "yyyy/MM/dd HH:mm:ss.fffffff";
private readonly ILogPathService _log_path;
private readonly IEssentialsService _essentials;
private readonly Encoding _enc;
private File? _file;
private readonly string _header;
keiji marked this conversation as resolved.
Show resolved Hide resolved

/// <summary>
/// 型'<see cref="Covid19Radar.Services.Logs.LogWriter"/>'の新しいインスタンスを生成します。
/// </summary>
/// <param name="logPath">ログファイルのパスを提供するサービスを指定します。</param>
/// <param name="essentials">環境情報を提供するサービスを指定します。</param>
public LogWriter(ILogPathService logPath, IEssentialsService essentials)
{
_log_path = logPath ?? throw new ArgumentNullException(nameof(logPath));
_essentials = essentials ?? throw new ArgumentNullException(nameof(essentials));
_enc = Encoding.UTF8;
_header = CreateLogHeaderRow();
}

/// <inheritdoc/>
public void Write(string message, string method, string filePath, int lineNumber, LogLevel logLevel)
{
#if !DEBUG
if (logLevel == LogLevel.Verbose || logLevel == LogLevel.Debug) {
return;
}
#endif
try {
var jstNow = Utils.JstNow();
string row = CreateLogContentRow(message, method, filePath, lineNumber, logLevel, jstNow, _essentials);
Debug.WriteLine(row);
this.WriteLine(jstNow, row);
} catch (Exception e) {
Debug.WriteLine(e.ToString());
}
}

private void WriteLine(DateTime jstNow, string line)
{
var file = _file;
string fname = _log_path.LogFilePath(jstNow);
if (file is null || file._path != fname) {
var newFile = new File(fname, _enc);
while (true) {
Takym marked this conversation as resolved.
Show resolved Hide resolved
if (Interlocked.CompareExchange(ref _file, newFile, file) == file) {
file?.Dispose();
break;
}
Thread.Yield();
file = _file;
}
file = newFile;
file._sw.WriteLine(_header);
}
file._sw.WriteLine(line);
}

/// <inheritdoc/>
public void Dispose()
{
File? file;
while (true) {
file = _file;
if (Interlocked.CompareExchange(ref _file, null, file) == file) {
file?.Dispose();
break;
}
Thread.Yield();
}
}

private static string CreateLogHeaderRow()
{
return CreateLogRow(
"output_date",
"log_level",
"message",
"method",
"file_path",
"line_number",
"platform",
"platform_version",
"model",
"device_type",
"app_version",
"build_number"
);
}

private static string CreateLogContentRow(
string message,
string method,
string filePath,
int lineNumber,
LogLevel logLevel,
DateTime jstDateTime,
IEssentialsService essentials)
{
return CreateLogRow(
jstDateTime.ToString(_dt_format),
logLevel.ToString(),
message,
method,
filePath,
lineNumber.ToString(),
essentials.Platform,
essentials.PlatformVersion,
essentials.Model,
essentials.DeviceType,
essentials.AppVersion,
essentials.BuildNumber
);
}

private static string CreateLogRow(params string[] cols)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

元実装と比べると複雑度が増しているように思います。
特定文字があったら置き換える処理と理解していますが、元実装のReplaceを使った方法で不都合は想定されますか?

置き換え文字列が多い場合は変換テーブルのようなものを作ってそれに基づいて処理をする(処理そのものはすっきりさせる)のがうれしいです。ご意見をうかがえればと思います。

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LINQ から for に替えて速度向上を図ろうとしました。後で性能比較します。(Replace と同時に Select も展開しています。)

Copy link
Contributor Author

@Takym Takym May 11, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

簡略化して試してみた所、LINQ より FOR の方が微妙に早くまたコードサイズも小さくなりました。

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

https://gist.github.com/Takym/e0a382ff63179c5a7b07bfc301e2914b

元の実装と本PRの実装の性能を比較しました。全体的に向上しています。

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ここは可読性優先でいきましょう! ミリ秒単位の差なら気になるところですが、ナノ秒なら無視しても良いレベルだと思います。

こういう提案があったことは記録として残すので、性能が問題になったら採用と言うことで。

private static string CreateLogRow(params string[] cols)
{
var sb = new StringBuilder();
for (int i = 0; i < cols.Length; ++i) {
if (i != 0) {
sb.Append(", ");
}
string s = cols[i];
sb.Append('\"');
for (int j = 0; j < s.Length; ++j) {
char ch = s[j];
switch (ch) {
case '\t':
sb.Append("\\t");
break;
case '\v':
sb.Append("\\v");
break;
case '\r':
sb.Append("\\r");
break;
case '\n':
sb.Append("\\n");
break;
case '\\':
case '\"':
sb.Append(ch);
sb.Append(ch);
break;
default:
sb.Append(ch);
break;
}
}
sb.Append('\"');
}
return sb.ToString();
}

Copy link
Contributor Author

@Takym Takym May 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

単位はナノ秒で書かれていますが、差は約0.5マイクロ秒程あります。
ログ出力処理は様々な場所で沢山呼ばれており、この小さい差は全体的には大きな影響を与えると思います。

Copy link
Contributor Author

@Takym Takym May 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

今は可読性と処理速度を両立したコードを試行錯誤しています。少し時間が掛かりそうです。すみません。

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

締め切りとかがあるわけではないので大丈夫ですよ。

ぼくの考えとして、このログ出力は必ずFile IOを伴うものです。ファイル入出力にかかる時間を考えると、提示いただいているナノ秒・マイクロ秒未満の差は誤差の域だとぼくは思っていて、現時点であまり頑張って縮める必要はないとも考えています。

ぼく自身、Androidではカスタムビューで60fpsを維持したまま複雑な描画処理をするのにどうするかとか、カメラプレビューの大きな画像データを可能な限り早く前処理して機械学習モデルに入力するとかしているので、場合によってはナノ秒単位の差が積み重なってアプリの体験として命取りになることは承知しています。

その上で、この部分はそこまでのことではないなと考えています。最初の方にいただいていた「ファイルハンドラーを開いて保持しておく。日付が変わっていたら新しいファイルで開き直す」があれば、Issueそのものは解決できると考えています。

処理速度については、現在、ファイルハンドラーを開いたり閉じたりするやり方でも、性能面で問題になっていないると言う認識はありません。また、ハンドラーを開いたり閉じたりしなくなる分、少なくとも性能は上がるものと期待しているので、性能については今後、問題になるようなことがあれば、そのときに対応すればいいと考えています。

Copy link
Contributor Author

@Takym Takym May 22, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

工夫して可読性と効率のバランスを取る事ができました。

  1. for 文を foreach 文に置き換えました。
    • 配列に対する foreachfor と同程度の性能を持つそうです。
  2. switch を文から式に変更して、何を何に変換しているか分かり易くしました。
    • この書き方は switch 式や Replace よりも見やすいと思います。
    • '変換前の文字' => '変換後の文字列'
  3. 三項演算子と破棄を利用して、左側に条件右側に値を配置しました。
    • 三項演算子は式ですので破棄は必ず書かなくてはなりません。
  4. カンマを入れるかどうかの判定を無くし行数を減らしました。
    • 動作効率も僅かながら向上しています。
  5. 動作効率については以下の点を気を付けました。
    • StringBuilder を使いました。
      • 元のコードと比べると、文字列を追加する順番も明確になり、可読性も高いと感じています。
    • ループの深さを最小限にしました。
      • 元のコードでは SelectReplaceJoin を使っており、ループ回数が多いです。
    • 文字列連結演算子は使わない様にしました。
      • 文字列連結演算子を使うと、メモリの確保が発生し、全体的に効率が落ちてしまいます。

private static string CreateLogRow(params string[] cols)
{
_ = _sb is null ? _sb = new StringBuilder()
: _sb.Clear();
foreach (string col in cols) {
_sb.Append(",\"");
foreach (char ch in col) {
string? escaped = ch switch {
'\t' => "\\t", '\v' => "\\v",
'\r' => "\\r", '\n' => "\\n",
'\\' => "\\\\", '\"' => "\"\"",
_ => null
};
_ = escaped is null ? _sb.Append(ch)
: _sb.Append(escaped);
}
_sb.Append('\"');
}
_sb.Remove(0, 1);
return _sb.ToString();
}

LINQ を使わずに書いてみましたが、どうでしょうか?

{
var sb = new StringBuilder();
for (int i = 0; i < cols.Length; ++i) {
if (i != 0) {
sb.Append(", ");
}
string s = cols[i];
sb.Append('\"');
for (int j = 0; j < s.Length; ++j) {
char ch = s[j];
switch (ch) {
case '\t':
sb.Append("\\t");
break;
case '\v':
sb.Append("\\v");
break;
case '\r':
sb.Append("\\r");
break;
case '\n':
sb.Append("\\n");
break;
case '\\':
case '\"':
sb.Append(ch)
.Append(ch);
Takym marked this conversation as resolved.
Show resolved Hide resolved
break;
default:
sb.Append(ch);
break;
}
}
sb.Append('\"');
}
return sb.ToString();
}

private sealed class File : IDisposable
{
internal readonly string _path;
internal readonly StreamWriter _sw;

internal File(string path, Encoding enc)
{
string dir = Path.GetDirectoryName(path);
if (!Directory.Exists(dir)) {
Directory.CreateDirectory(dir);
}

_path = path;
_sw = new StreamWriter(new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite), enc);
_sw.AutoFlush = true;
}

public void Dispose()
{
_sw.Dispose();
}
}
}
}
Loading