.net framework での現在時刻取得のオーバーヘッドについてのメモ
.net にて、タイムスタンプ*1を低精度で良いので高速に得たかったのだが、どの方法が早いのかについてあまり情報がなかったので、やってみた。
やった実験
以下のプロパティをそれぞれ 1048576 (2^20) 回呼び出すメソッドを 4 回呼び出すコードを Debug ビルドし、 Windows 7 (32 bit) 環境にて実行した。
- (空)
- なにもしない空のループを回す
- Environment.TickCount
- DateTime.Now.Ticks
- DateTime.UtcNow.Ticks
- Stopwatch.ElapsedMilliseconds
- Stopwatch のインスタンスは一つのループで使いまわす
結果(概略)
2〜3 回目の結果を集計すると、以下のようになった(全データは後述)。
プロパティ | 2^20 回 [ms] | 一回当たり [μs/call] | |
---|---|---|---|
Environment.TickCount | 2.53 | 0.0024 | |
DateTime.Now.Ticks | 156.85 | 0.15 | |
DateTime.UtcNow.Ticks | 18.84 | 0.018 | |
Stopwatch.ElapsedMilliseconds | 43.44 | 0.041 |
- 2^20 回 [ms]: (ループ全体所要時間の平均) - (空ループ 2^20 回の平均)
- 一回当たり [μs/call]: 2^20 回、の値を 2^20 で割った値 (マイクロ秒に換算)
所感
- Environment.TickCount が高速である
- DateTime.UtcNowの 7 倍以上、Stopwatch の 17 倍以上
- DateTime.Now はかなり遅い
- 実は Stopwatch はそれほど極端には遅くない
- 高精度な代わりに遅い、と巷ではよく言われているが・・・
- DateTime.UtcNow の 2.3 倍程度である
- DateTime.Now よりははるかに速い
要するに、とにかく高速に時間を取得したい場合には、Environment.TickCount を使った方がよさそうだ。
ただし、Environment.TickCount は約 24.9 日であふれる*4という仕様であり、いまどき 30 日程度連続稼働する PC など珍しくはない(はず)なので、扱いにとても注意が必要である。たとえ 30 日も連続稼働しないであろうプログラムでも、約 24.9 日の境界をまたぐと値の大小関係が狂うので注意が必要であることに変わりがない。
また、高精度タイマーが遅いという先入観を根拠とした判断*5は必ずしも妥当ではないことも頭の片隅に置いておいてよいだろう。
加えて、ついつい使ってしまいがちな DateTime.Now は、ローカル日時が必要な場合に限って使うべきであり、ある二つの時点の時間差を知る用途には UtcNow (か Stopwatch や Environment.TickCount)を使うべきであろう。
結果(詳細)
Empty roop: 3.5261 [ms], 3.36275100708008E-06 [ms/call] Environment.TickCount: 6.346 [ms], 6.05201721191406E-06 [ms/call] DateTime.Now.Ticks: 162.7851 [ms], 0.000155243968963623 [ms/call] DateTime.UtcNow.Ticks: 22.4571 [ms], 2.14167594909668E-05 [ms/call] Stopwatch.ElapsedMilliseconds: 54.7306 [ms], 5.21951675415039E-05 [ms/call] ---------------- Empty roop: 5.4742 [ms], 5.22060394287109E-06 [ms/call] Environment.TickCount: 6.6567 [ms], 6.34832382202149E-06 [ms/call] DateTime.Now.Ticks: 163.9675 [ms], 0.000156371593475342 [ms/call] DateTime.UtcNow.Ticks: 21.4703 [ms], 2.04756736755371E-05 [ms/call] Stopwatch.ElapsedMilliseconds: 46.5926 [ms], 4.44341659545898E-05 [ms/call] ---------------- Empty roop: 3.1857 [ms], 3.03812026977539E-06 [ms/call] Environment.TickCount: 6.5811 [ms], 6.27622604370117E-06 [ms/call] DateTime.Now.Ticks: 149.1435 [ms], 0.000142234325408936 [ms/call] DateTime.UtcNow.Ticks: 23.2336 [ms], 2.21572875976563E-05 [ms/call] Stopwatch.ElapsedMilliseconds: 45.3947 [ms], 4.32917594909668E-05 [ms/call] ---------------- Empty roop: 3.1815 [ms], 3.03411483764648E-06 [ms/call] Environment.TickCount: 6.204 [ms], 5.91659545898438E-06 [ms/call] DateTime.Now.Ticks: 169.2678 [ms], 0.00016142635345459 [ms/call] DateTime.UtcNow.Ticks: 23.645 [ms], 2.25496292114258E-05 [ms/call] Stopwatch.ElapsedMilliseconds: 50.1856 [ms], 4.78607177734375E-05 [ms/call] ---------------- |tickCount|2.53346666666667|0.00241610209147135| |dt_ticks|156.8458|0.149579811096191| |dt_UTCticks|18.8358333333333|0.0179632504781087| |sw_ms|43.4438333333333|0.0414312680562337|
実験に使ったコード
public void Test() { this.result["tickCount"] = new List<TimeSpan>(); this.result["dt_ticks"] = new List<TimeSpan>(); this.result["dt_UTCticks"] = new List<TimeSpan>(); this.result["sw_ms"] = new List<TimeSpan>(); for (var i = 0; i < 4; i++) { TestCore(); Console.WriteLine("----------------"); } foreach (var name in this.result.Keys) { this.ShowSummary(name); } } private List<TimeSpan> empty = new List<TimeSpan>(); private Dictionary<string, List<TimeSpan>> result = new Dictionary<string, List<TimeSpan>>(); private void ShowSummary(string name) { var sum = result[name].Skip(1).Average((ts) => ts.TotalMilliseconds) - empty.Skip(1).Average((ts) => ts.TotalMilliseconds); var per = sum / Times; Console.WriteLine(string.Format("|{0}|{1}|{2}|", name, sum, per * 1000)); } private const int Times = 1024 * 1024; private void TestCore() { var sw = new Stopwatch(); sw.Start(); for (var i = 0; i < Times; i++) { } sw.Stop(); Console.WriteLine("Empty roop: {0} [ms], {1} [ms/call]", sw.Elapsed.TotalMilliseconds, sw.Elapsed.TotalMilliseconds / (float)Times); this.empty.Add(sw.Elapsed); sw.Restart(); for (var i = 0; i < Times; i++) { var t = Environment.TickCount; } sw.Stop(); Console.WriteLine("Environment.TickCount: {0} [ms], {1} [ms/call]", sw.Elapsed.TotalMilliseconds, sw.Elapsed.TotalMilliseconds / (float)Times); this.result["tickCount"].Add(sw.Elapsed); sw.Restart(); for (var i = 0; i < Times; i++) { var t = DateTime.Now.Ticks; } sw.Stop(); Console.WriteLine("DateTime.Now.Ticks: {0} [ms], {1} [ms/call]", sw.Elapsed.TotalMilliseconds, sw.Elapsed.TotalMilliseconds / (float)Times); this.result["dt_ticks"].Add(sw.Elapsed); sw.Restart(); for (var i = 0; i < Times; i++) { var t = DateTime.UtcNow.Ticks; } sw.Stop(); Console.WriteLine("DateTime.UtcNow.Ticks: {0} [ms], {1} [ms/call]", sw.Elapsed.TotalMilliseconds, sw.Elapsed.TotalMilliseconds / (float)Times); this.result["dt_UTCticks"].Add(sw.Elapsed); sw.Restart(); var stopwatch = new System.Diagnostics.Stopwatch(); for (var i = 0; i < Times; i++) { var t = stopwatch.ElapsedMilliseconds; } sw.Stop(); Console.WriteLine("Stopwatch.ElapsedMilliseconds: {0} [ms], {1} [ms/call]", sw.Elapsed.TotalMilliseconds, sw.Elapsed.TotalMilliseconds / (float)Times); this.result["sw_ms"].Add(sw.Elapsed); }