私たちはいくつかのパフォーマンスの問題をデバッグしていて、ストップウォッチからいくつかの奇妙な結果に気づきました。
- Webサービスを呼び出すクライアントがあります
- ストップウォッチを使用して、Webサービスのサービスレイヤーで時間を記録します
- 下位層の時刻をdatetime.now.ticksで記録します
レイヤー2は、2行のロギングを備えた単なるパススルーレイヤーです。
記録された時間は次のとおりです。
- 110ミリ秒
- 52125ミリ秒
- 125ミリ秒
1ミリ秒まで正確なAPIはありませんが、2は1未満であると予想していました。
サービスコールごとに新しいストップウォッチを作成するため、これは古いストップウォッチタールが再起動された時間ではありません。
なぜ私たちがこれらの数字を取得しているのか誰もが知っていますか?
編集
2と3は同じマシンと同じアプリドメイン上にあります
ストップウォッチコードは次のとおりです。
var sw = new Stopwatch();
sw.Start();
//code to call layer 3
sw.Stop();
orchestrationContext.LogOperationTime(functionName, sw.ElapsedMilliseconds);
レイヤー3での時間のロギング
protected DateTime StartTime { get; set; }
StartTime = DateTime.Now;
// code
new TimeSpan(DateTime.Now.Ticks - StartTime.Ticks).Milliseconds
1のロギングは別のマシン上にあり、Websphereを使用してロギングします。